recomended way to check longest period that interupts are disabled ?

recomended way to check longest period that interupts are disabled ?

[Mike Mattie]

[-- Attachment #1: Type: text/plain, Size: 1273 bytes --]

Hello,

I am still struggling to track down problems with audio playback. I get intermittent:

Apr 26 02:01:40 reforged [13230.947879] cannot submit sync urb (err = -45)

I have tackled the scheduler issues to where I really don't think the
driver is being starved at all. I am running audacious like so:

schedtool -R -p 50 -n 1 -e audacious

At this point the strongest correlation I can get is that starting
programs seems to trigger the stutter. I have suspected IO for
some time.

My system image , / & /usr are on a libata (VIA PATA) driver.
I have disabled the write-cache , but I also have noatime set
on mount, for /usr

My big suspicion is that one of my drivers, likely IO is
disabling interrupts for too long.

I have looked but not found a tool for measuring the longest
period interrupts are disabled and pointing the finger at
the culprit, could anyone on this list recommend tools that
might help me pinpoint what is going on ?

I would also be delighted for any sort of recommended latency
testing tools.

pin-pointing this is going to be a "learning experience" but
every time I think I am about to have a bonding moment with 
the kernel audio skips; I am highly motivated.

Cheers,
Mike Mattie - codermattie@gmail.com

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: recomended way to check longest period that interupts are disabled ?

[Peter Zijlstra]

On Thu, 2007-04-26 at 02:13 -0700, Mike Mattie wrote:
> Hello,
> 
> I am still struggling to track down problems with audio playback. I get intermittent:
> 
> Apr 26 02:01:40 reforged [13230.947879] cannot submit sync urb (err = -45)
> 
> I have tackled the scheduler issues to where I really don't think the
> driver is being starved at all. I am running audacious like so:
> 
> schedtool -R -p 50 -n 1 -e audacious
> 
> At this point the strongest correlation I can get is that starting
> programs seems to trigger the stutter. I have suspected IO for
> some time.
> 
> My system image , / & /usr are on a libata (VIA PATA) driver.
> I have disabled the write-cache , but I also have noatime set
> on mount, for /usr
> 
> My big suspicion is that one of my drivers, likely IO is
> disabling interrupts for too long.
> 
> I have looked but not found a tool for measuring the longest
> period interrupts are disabled and pointing the finger at
> the culprit, could anyone on this list recommend tools that
> might help me pinpoint what is going on ?
> 
> I would also be delighted for any sort of recommended latency
> testing tools.
> 
> pin-pointing this is going to be a "learning experience" but
> every time I think I am about to have a bonding moment with 
> the kernel audio skips; I am highly motivated.

The -rt kernel contains a full latency tracer.

http://people.redhat.com/mingo/realtime-preempt/

Some hardware just isn't up to the job though...

Re: recomended way to check longest period that interupts are disabled ?

[Mike Mattie]

[-- Attachment #1: Type: text/plain, Size: 5098 bytes --]

On Thu, 26 Apr 2007 13:11:52 +0200
Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:

> On Thu, 2007-04-26 at 04:02 -0700, Mike Mattie wrote:
> > On Thu, 26 Apr 2007 11:53:57 +0200
> > Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:
> > 
> > > On Thu, 2007-04-26 at 02:13 -0700, Mike Mattie wrote:
> > > > Hello,
> > > > 
> > > > I am still struggling to track down problems with audio
> > > > playback. I get intermittent:
> > > > 
> > > > Apr 26 02:01:40 reforged [13230.947879] cannot submit sync urb
> > > > (err = -45)
> > > > 
> > > > I have tackled the scheduler issues to where I really don't
> > > > think the driver is being starved at all. I am running
> > > > audacious like so:
> > > > 
> > > > schedtool -R -p 50 -n 1 -e audacious
> > > > 
> > > > At this point the strongest correlation I can get is that
> > > > starting programs seems to trigger the stutter. I have
> > > > suspected IO for some time.
> > > > 
> > > > My system image , / & /usr are on a libata (VIA PATA) driver.
> > > > I have disabled the write-cache , but I also have noatime set
> > > > on mount, for /usr
> > > > 
> > > > My big suspicion is that one of my drivers, likely IO is
> > > > disabling interrupts for too long.
> > > > 
> > > > I have looked but not found a tool for measuring the longest
> > > > period interrupts are disabled and pointing the finger at
> > > > the culprit, could anyone on this list recommend tools that
> > > > might help me pinpoint what is going on ?
> > > > 
> > > > I would also be delighted for any sort of recommended latency
> > > > testing tools.
> > > > 
> > > > pin-pointing this is going to be a "learning experience" but
> > > > every time I think I am about to have a bonding moment with 
> > > > the kernel audio skips; I am highly motivated.
> > > 
> > > The -rt kernel contains a full latency tracer.
> > > 
> > > http://people.redhat.com/mingo/realtime-preempt/
> > 
> > Thanks for the response. That is very helpful. I had
> > looked at it briefly before but at a glance it looked
> > like building a pro-audio workstation, which was a bit
> > over the top for me. At a closer examination most of the
> > stuff in -rt looks generally useful.
> > 
> > > Some hardware just isn't up to the job though...
> > 
> > I don't quite understand this. I have a athlon XP 3000+
> > and an audigy NX. Even using the libsamplerate library
> > audacious + alsa only uses 12% of the processor tops.
> > 
> 
> Some (broken) hardware, like some VIA IDE controllers just take
> forever to do their thing. In which case you're stuck with it. Not
> all x86 hardware is build to equal standards :-(
> 
> quite honestly, x86 hardware is a mess.

No disagreement there. It's really hard to pick good
hardware other than remembering the odd kernel hacker
comments , or grepping for expletives in the source
and piping through wc :)

> > 
> > my next step is to go out and buy a usb card so I can
> > see if I can get the audigy NX on it's own interrupt.
> 
> I'd try to pinpoint the latency first, might safe on expenses.

definitely.

> > from a look at -RT I need to do this before I can use
> > the fun stuff like interrupt prioritization.
> > 
> > Maybe a naive question but with the HIRES_TIMERS
> > stuff merged, can the stats/diagnostics now merge
> > into the mainline , or be broken out as a seperate patch ? 
> 
> Not sure, it might be. Ingo does all that.
> 
> > I would really like to see what exactly the mainline is doing , 
> > especially so I can come up with a answer for what exactly is
> > wrong with the current system. I would like to change
> > my system knowing what the change is , rather than
> > saying "-rt works but I don't know why".
> 
> If its a hardware latency, -rt will suffer equally. Either way,
> running -rt will teach you something. Either its mainline borkage, or
> hardware.
> 
> > One thought I had is that I could use the -rt patches
> > as a starting place for some SystemTap probes. Looking
> > down the road that seems to be the most durable option.
> 
> Might be, although do remember that traps cost too. But I'm not really
> familiar with all of this.
> 

Thanks for the comments. After running cyclictest it definitely looks
like the average jitter is really low, around 7-8 . The max is really
high , >100

If I am interpreting this correctly for the most part the jitter is
pretty low, but something horrible is happening that blows up the
max value.

./cyclictest -p 30 -t 6
2.00 1.84 1.41 3/120 13760

T: 0 (13130) P:30 I:1000 C:  42763 Min:      4 Act:   10 Avg:    8 Max:     133
T: 1 (13131) P:29 I:1500 C:  28509 Min:      4 Act:    6 Avg:    7 Max:     114
T: 2 (13132) P:28 I:2000 C:  21382 Min:      4 Act:    7 Avg:    6 Max:     157
T: 3 (13133) P:27 I:2500 C:  17106 Min:      4 Act:   11 Avg:    7 Max:     110
T: 4 (13134) P:26 I:3000 C:  14255 Min:      4 Act:    8 Avg:    7 Max:    1011
T: 5 (13135) P:25 I:3500 C:  12218 Min:      4 Act:   12 Avg:    8 Max:     118


Cheers,
Mike Mattie

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: recomended way to check longest period that interupts are disabled ?

[Thomas Gleixner]

On Thu, 2007-04-26 at 05:19 -0700, Mike Mattie wrote:
> Thanks for the comments. After running cyclictest it definitely looks
> like the average jitter is really low, around 7-8 . The max is really
> high , >100
> 
> If I am interpreting this correctly for the most part the jitter is
> pretty low, but something horrible is happening that blows up the
> max value.

Yup

> ./cyclictest -p 30 -t 6
> 2.00 1.84 1.41 3/120 13760
> 
> T: 0 (13130) P:30 I:1000 C:  42763 Min:      4 Act:   10 Avg:    8 Max:     133
> T: 1 (13131) P:29 I:1500 C:  28509 Min:      4 Act:    6 Avg:    7 Max:     114
> T: 2 (13132) P:28 I:2000 C:  21382 Min:      4 Act:    7 Avg:    6 Max:     157
> T: 3 (13133) P:27 I:2500 C:  17106 Min:      4 Act:   11 Avg:    7 Max:     110
> T: 4 (13134) P:26 I:3000 C:  14255 Min:      4 Act:    8 Avg:    7 Max:    1011
> T: 5 (13135) P:25 I:3500 C:  12218 Min:      4 Act:   12 Avg:    8 Max:     118

What happens with 

# cyclictest -p 80 -n

At first it puts the timer thread above everything else and second it
uses nanosleep instead of the signal delivered posix timers.

	tglx