[linux-audio-user] xrun madness

[Joel White]

Hi, all,

Sorry for the length, here, but I'm out of ideas for things to try!

Back in June, I wrote to the list lamenting xruns in my system using 
jackd and ardour with a Delta 1010LT and an Adaptec 7890 SCSI 
controller.  I was trying out early 2.6 kernels, but ended up going back 
to a 2.4.23 with low latency patches, but there were still xruns with 
the 2.4.23 kernel.  I came across info suggesting the problem was the 
Adaptec controller:

http://eca.cx/lau/2004/06/0000.html

I ended up adding an IDE drive to use for audio, and things seemed to work:

http://eca.cx/lau/2004/06/0026.html

I've continue fussing with the system to try and figure out the SCSI 
problem.  "Why bother?" you ask?  Well, my system is still on the SCSI 
Raid0 and occassionally I still get an xrun (last night, the 
"occasional" became "in the middle of 3 or 4 attempts to lay down basic 
tracks with the band" - arrggh!), even when I've shut off just about all 
processes.  I can really pile up the xruns while recording to the IDE 
drive by coping a big file on the SCSI Raid0, suggesting again a problem 
with the Adaptec.

I wrote to Justin Gibbs, who worked on the aic7xxx driver.   He said 
that the contention expressed on the ST Audio website (referenced in the 
first message linked above) that the Adaptec keeps steady access to the 
PCI bus was "complete hogwash."  He mentioned that there may be problems 
with the latency timer settings on the devices, so I've tried just about 
every possible combination of latency timer settings for the AIC7890 and 
the 1010LT, but nothing changes the number of xruns when recording to 
the SCSI Raid0 (about 30 in a 1 min recording session, 8 channels, -n 2 
-p 256).  So that doesn't seem to be it.

Justin expressed doubts about whether the AIC7890 was the problem, but 
it is clear that the xruns are linked to disk writes (I monitored iostat 
while recording, and the xruns occured when the disks were written to). 
This seems rather damning, but I've found that I can record to the SCSI 
Raid0 with no xruns at all when running Capture only, with periods down 
to 128.  Iostat shows the same amount of disk activity.  Interestingly, 
running in Duplex mode on the SCSI Raid0, I cannot eliminate xruns even 
with the largest period possible (something like -n 2 -p 2048) - I will 
still get occasional xruns.

In an effort to track down the problem, with Lee Revell's help (thanks, 
Lee!) I've tried out the recent 2.6.9-rc2-mm4-VP-S7 kernel to take 
advantage of its kernel latency tracing capabilities.  Turning on all 
the preempt and latency doo-dads shows that the max kernel latency to be 
around 200 - 400 usec when recording to either the SCSI Raid0 or IDE 
disks.  This kernel latency is far below the 5.8ms period time (-p 256 
-r 44100).  Unfortunately, I still get xruns when recording to either 
disk (about 30 in 30 sec of recording).  The xrun diagnostics don't 
really tell me much, either.  I get a lot of:

Oct 18 22:09:38 darth XRUN: pcmC0D0p
Oct 18 22:09:38 darth [<e0a316a0>] snd_pcm_period_elapsed+0x280/0x3f0 
[snd_pcm]
Oct 18 22:09:38 darth [<c02e1613>] schedule+0x403/0x7d0
Oct 18 22:09:38 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:09:38 darth [<c0111608>] mcount+0x14/0x18
Oct 18 22:09:38 darth [<e0a447f6>] snd_ice1712_interrupt+0x1a6/0x230 
[snd_ice171
2]
Oct 18 22:09:38 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:09:38 darth [<c0133c90>] do_hardirq+0x70/0xe0
Oct 18 22:09:38 darth [<c0133e24>] do_irqd+0x124/0x1f0
Oct 18 22:09:38 darth [<c0132b5b>] kthread+0xbb/0xc0
Oct 18 22:09:38 darth [<c0133d00>] do_irqd+0x0/0x1f0
Oct 18 22:09:38 darth [<c0132aa0>] kthread+0x0/0xc0
Oct 18 22:09:38 darth [<c0102779>] kernel_thread_helper+0x5/0xc
Oct 18 22:09:38 darth XRUN: pcmC0D0p
Oct 18 22:09:38 darth [<e0a316a0>] snd_pcm_period_elapsed+0x280/0x3f0 
[snd_pcm]
Oct 18 22:09:38 darth [<c02e1613>] schedule+0x403/0x7d0
Oct 18 22:09:38 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:09:38 darth [<c0111608>] mcount+0x14/0x18
Oct 18 22:09:38 darth [<e0a447f6>] snd_ice1712_interrupt+0x1a6/0x230 
[snd_ice171
2]
Oct 18 22:09:38 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:09:38 darth [<c0133c90>] do_hardirq+0x70/0xe0
Oct 18 22:09:38 darth [<c0133e24>] do_irqd+0x124/0x1f0
Oct 18 22:09:38 darth [<c0132b5b>] kthread+0xbb/0xc0
Oct 18 22:09:38 darth [<c0133d00>] do_irqd+0x0/0x1f0
Oct 18 22:09:38 darth [<c0132aa0>] kthread+0x0/0xc0
Oct 18 22:09:38 darth [<c0102779>] kernel_thread_helper+0x5/0xc
Oct 18 22:10:10 darth XRUN: pcmC0D0p
Oct 18 22:10:10 darth [<e0a316a0>] snd_pcm_period_elapsed+0x280/0x3f0 
[snd_pcm]
Oct 18 22:10:10 darth [<c02e1613>] schedule+0x403/0x7d0
Oct 18 22:10:10 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:10:10 darth [<c0111608>] mcount+0x14/0x18
Oct 18 22:10:10 darth [<e0a447f6>] snd_ice1712_interrupt+0x1a6/0x230 
[snd_ice171
2]
Oct 18 22:10:10 darth [<c0133516>] handle_IRQ_event+0x36/0x70
Oct 18 22:10:10 darth [<c0133c90>] do_hardirq+0x70/0xe0
Oct 18 22:10:10 darth [<c0133e24>] do_irqd+0x124/0x1f0
Oct 18 22:10:10 darth [<c0132b5b>] kthread+0xbb/0xc0
Oct 18 22:10:10 darth [<c0133d00>] do_irqd+0x0/0x1f0
Oct 18 22:10:10 darth [<c0132aa0>] kthread+0x0/0xc0
Oct 18 22:10:10 darth [<c0102779>] kernel_thread_helper+0x5/0xc

If anyone can help interpret this, I'm all ears/eyes!

Under this kernel, running in Capture mode does not generate any xruns, 
but jackd halts ardour after about a minute of recording with a 
"subgraph starting at ardour timed out" error.  Capture mode with the 
2.4.23 kernel seems to work fine recording to either disk.

One more bit of info: Running jackd in verbose mode, under 2.4.23 the 
max usec runs around 800-1000 when there are no xruns (still well below 
the 5.8ms period).  Under 2.4.9, the max usec run between 1100-2000 (odd 
that it is higher with the different kernel, but still below the 5ms).  
Most xruns are below 1 ms.

Oh, and I _never_ get an xrun during playback, even in Duplex mode.

I have a Gentoo system, so after seeing recent messages about potential 
issue with Gentoo, I tried booting the Demudi LiveCD to test things.  I 
didn't get far - with no clients, qjackctl showed frequent xruns "just 
idling."  I figured I'd stick to debugging the Gentoo system, since it 
seemed to be closer to working.

At this point, Lee's stumped, and I've run out of things to try.  It 
doesn't seem to be a kernel latency problem per se, but there are 
clearly differences between what is going on under the two kernels.

"Why not just run in Capture mode with hardware monitoring?" you ask?  
Well, that is certainly a possibility, but it is a pain in the butt to 
record some tracks, then have to stop ardour, stop jack, restart jack in 
duplex (or play) and restart jack to hear what's been recorded, then 
redo the process to go back to recording.  Plus, I've had xruns when 
I've tried to overdub a single channel (where I have to run in duplex)!  
Not as bad as having an xrun halt ardour while the whole band is laying 
down basic tracks, but bad enough.

If anyone has any ideas on things to try, test, whatever, I'd be happy 
to give it a go.  I feel like I could be close to having a good system 
for recording my band, but last night was pretty frustrating!

Thanks for "listening"!

Joel