[alsa-devel] Timer instability

[Takashi Iwai]

At Mon, 09 Mar 2009 12:20:51 +0100,
I wrote:
> 
> At Mon, 9 Mar 2009 11:13:21 +0000,
> Clive Messer wrote:
> > 
> > On Tuesday 03 Mar 2009 17:41:22 Takashi Iwai wrote:
> > 
> > > > Hrm, but still an unexpected jump is found.
> > > >
> > > > If you build the driver with CONFIG_SND_PCM_XRUN_DEBUG=y, you must
> > > > have /proc/asound/card0/pcm0p/xrun_debug.  Echo 1 to this (as root)
> > > > 	echo 1 > /proc/asound/card0/pcm0p/xrun_debug
> > > > and try the program, see whether any debug message appears.
> > > > If any message appears, it means basically an unstable hardware.
> > > >
> > > > Also, the below is a patch I tried to clean up and improve the
> > > > handling.  Give it a try (and do echo 1 above for testing).
> > >
> > > BTW, the original test program is very hard to see what's wrong
> > > because it spews out way too many lines.  The below is a filtered-out
> > > version.
> > >
> > > It prints only unexpected jumps of avail values (the threshold is
> > > set 100 blindly).  The output is like below:
> > >
> > > 	% ./alsa-time-test hw
> > > 	21720872	(4987)	delta 216	avail 216	delay 4200
> > > 	21943118	(65)	delta 208	avail 208	delay 4208
> > > 	23752310	(3)	delta 232	avail 232	delay 4184
> > > 	23761847	(5972)	delta 264	avail 264	delay 4152
> > >
> > > The first column is the usec from the program start, the next value in
> > > parentheses is the time-step from the last time of status changes,
> > > the delta is the increase of avail, and the rest are raw values.
> > >
> > > If a too large delta appears in a short time-step, something is wrong.
> > > If it appears in a large time-step, it's simply a wrong responsiveness
> > > (aka system latency).
> > 
> > Hello Takashi/Lennart,
> > 
> > Sorry, I have been busy for a few days.
> > I patched my kernel (kernel-2.6.29-0.53.rc7.fc10.x86_64) with your pcm_lib.c 
> > patch and 'echo 1 > /proc/asound/card0/pcm0p/xrun_debug'.
> > 
> > I have done several runs with the new alsa-time-test.c code. Typically I get a 
> > bunch of kernel dmesg when I start the alsa-time-test program but not 
> > afterwards. Just a reminder - I'm running this on fast hardware - X58 / Core 
> > i7 920 - the machine is not loaded at all, so latency should be very low. 
> > snd_hda_intel - ' 00-00: AD198x Analog : AD198x Analog : playback 1 : capture 
> > 3'.
> > 
> > Here is an example run .....
> > 
> > hw_ptr skipping! (pos=2096, delta=2096, period=1472)
> > hw_ptr skipping! (pos=2096, delta=2096, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> > hw_ptr skipping! (pos=3600, delta=3600, period=1472)
> 
> Thanks.  This implies that the position pointer once reads zero
> then the next value gets screwed up.  It shows the DMA pointer
> read is pretty unreliable on your hardware.  It's obviously bad for
> PA because the DMA pointer is the only trusted information for
> glitch-free.  For the traditional method, this isn't usually so
> critical, though.
> 
> > 9901323          (2632)  delta 111       avail 117       delay 4299
> > 19901290        (2599)  delta 112       avail 112       delay 4304
> > 29901285        (3)     delta 112       avail 112       delay 4304
> > 39901315        (2624)  delta 120       avail 120       delay 4296
> > 49901317        (2626)  delta 112       avail 112       delay 4304
> > 59901317        (2625)  delta 112       avail 112       delay 4304
> > 69901323        (2632)  delta 118       avail 118       delay 4298
> > 79901391        (3)     delta 120       avail 120       delay 4296
> > 89901327        (2634)  delta 112       avail 112       delay 4304
> > 99901283        (2591)  delta 120       avail 120       delay 4296
> > 109901334       (2642)  delta 120       avail 120       delay 4296
> > 119901320       (2627)  delta 112       avail 112       delay 4304
> 
> These outputs look fairly OK.  The latency is about 2.5 ms and it's
> about 110 samples.  That us, as long as the outputs look like above,
> your system is working fine with my patch.

As the patch seems working with other tests, too, I merged it
(with a slight clean-up) into sound git tree now.


Takashi