Hi folks,
I've spent some time this week trying to debug frequent hiccups in my
audio playback, on my USB sound card. The short version is that it seems
the 24 ms worth of queued URBs is not enough, since the urb complete handler
is frequently called too late and sometimes more than 16ms (plus 8ms in
the urb that completed is 24ms) too late, causing a hiccup in the sound.
My detailed analysis follows.
- I was having hiccups when playing audio on my Terratec Aureon 5.1 MkII.
- The hiccups occured frequently when running through pulseaudio with
timer-based scheduling (tsched=1) and didn't seem to occur when
running pulseaudio in the "regular" interrupt-driven mode (tsched=0),
but later analysis suggests that they still occur, but only very
rarely. I've not found an explanation for this difference, though.
- These hiccups have been occuring for quite some time, but I've been
working around then with tsched=0 so far. All of the data gathered in
this mail, was done using kernel 3.6.0-rc5.
- While playing audio, I frequently got these messages:
delay: estimated 240, actual 768
delay: estimated 1152, actual 768
They always seem to occur in pairs, (which makes sense since the
first urb completion is late, but the subsequent one is early). On
every hiccup, I saw a delay message, but there was not always a
hiccup when a delay message occurred. It seems that the hiccups only
occur when the estimated delay is 0 (meaning it's really less than 0,
i.e. no delay left -> hiccup).
delay: estimated 0, actual 384
delay: estimated 384, actual 768
- My problem seems Similar to a recent report on alsa-devel [2].
However, that report suggested the problem occured only with an idle
CPU, while I've observed the problem regardless of CPU usage.
- These messages are because the urb completion handler is not always
called in time, probably because the hardware interrupt is somehow
delayed (as suggested by [1]). This happens frequently, mostly during
user interaction (switching virtual desktops, changing tabs in the
browser). Since the completed urb is resubmitted in the completion
handler, the USB hardware runs out of data to send when the
completion handler is called more than 16ms too late.
Note that the completion handler is called at exactly the expected
moment (8 frames after the previous one) most of the time.
Also, if urb->start_frame is not lying, the urbs that have their
completion handler called late did get sent out at the right time, so
the problem is only that the completion handler is late.
- By default, the usb snd driver creates three URBs containg 8ms of
data each, giving me a 24ms buffer (even though the ALSA period size
is a lot bigger, 1000ms currently). The urb size and count
calculation in data_ep_set_params initially comes up with a buffer of
period_size ms, but this is then limited to 24ms because of
MAX_QUEUE.
- I can increase the buffer size a bit using the nrpacks module
parameter. The maximum setting of 20 packets/urb, gets me a buffer of
40ms (the max_queue tries to limit it again, but since there must be
two URBs at minimum, I get 40ms). Using this slightly larger buffer,
the hiccups disappear as good as completely. The delays are still
there, but apparently they hardly ever get over 20ms.
- When I tried to double-check something this morning with a clean
kernel without debugging stuff added, I found out the problem wasn't
occuring at all, even without passing the nrpacks parameter and with
tsched=1. I'm not sure what happened there, but presumable there is
some extra environmental factor involved that I'm missing here
(I checked everything I could think of, plugged in hardware, running
processes, doing a standby and hibernate, etc.).
- I also found a second form of hiccuping that was even more frequent
(up to a few times per second sometimes). However, these did not go
paired with delay messages and were always solved by restarting
pulseaudio, so I'm assuming this is a completely separate issue.
- There was a recent thread on this list about handling delays in
isochronous transfers [2]. However, this posting is more concerned
with recovering after a hiccup, without introducing extra
(cumulative) latency, which is important for interactive / realtime
audio streams. For my music stream this doesn't really pose a
problem, I'm more concerned with preventing the hiccups in the first
place (and extra latency is not a problem for me).
[1]: http://www.spinics.net/lists/linux-usb/msg69998.html
[2]: http://mailman.alsa-project.org/pipermail/alsa-devel/2012-April/051345.html
So, the real question in this mail is: What can we do to fix this? I've
found out I can somewhat influence the queue size with the nrpacks
variable, which can fix the issue for me, but I'd rather see this work
by default for everyone.
So, a few more considerations:
- Why is the queue size limited to only 24ms right now? I rather like
the idea of using pulseaudio and a very big buffer to reduce wakeups
and thus power usage. Since pulseaudio is keeping a 1000ms buffer in
my setup, why shouldn't (a large part of) this buffer not be queued
in urbs to make sure the USB hardware can keep sending data without
waking up the host system? AFAICS, this would require increasing the
size of urbs, not just the number of urbs, since an interrupt is
normally fired after each urb, right? Also, there's probably other
(performance) considerations that my slightly naive mind is not
seeing, so please enlighten me :-)
- In any case, increasing the queue size even a bit helps to fix this
problem on my particular hardware setup, so probably also on others.
If the queue size is increased by changing MAX_QUEUE, this would help
for high-latency applications where the hardware is sometimes slow,
like my setup, but would still allow for low-latency applications
when the period_size is set to a small value.
- Or are the delays in the urb completion handler / interrupt by
definition a bug in (some other part of) the code? In that case, I
might be able to dig in deeper to find and fix the cause of the
delays, if someone can offer some suggestions about where to look for
the problem.
Gr.
Matthijs
Attachment:
signature.asc
Description: Digital signature
