[alsa-devel] Timer instability

[Takashi Iwai]

At Tue, 03 Mar 2009 17:05:31 +0100,
I wrote:
> 
> At Wed, 25 Feb 2009 18:34:31 +0000,
> Clive Messer wrote:
> > 
> > On Wednesday 25 Feb 2009 18:13:47 Takashi Iwai wrote:
> > 
> > > > > diff --git a/src/pcm/pcm_hw.c b/src/pcm/pcm_hw.c
> > > > > index e9ce092..5211d1c 100644
> > > > > --- a/src/pcm/pcm_hw.c
> > > > > +++ b/src/pcm/pcm_hw.c
> > > > > @@ -131,6 +131,10 @@ struct timespec snd_pcm_hw_fast_tstamp(snd_pcm_t
> > > > > *pcm) static int sync_ptr1(snd_pcm_hw_t *hw, unsigned int flags)
> > > > >  {
> > > > >         int err;
> > > > > +       long old_hwptr, new_hwptr;
> > > > > +       long old_applptr, new_applptr;
> > > > > +       old_hwptr = hw->sync_ptr->s.status.hw_ptr;
> > > > > +       old_applptr = hw->sync_ptr->c.control.appl_ptr;
> > > > >         hw->sync_ptr->flags = flags;
> > > > >         err = ioctl((hw)->fd, SNDRV_PCM_IOCTL_SYNC_PTR,
> > > > > (hw)->sync_ptr); if (err < 0) {
> > > > > @@ -138,6 +142,11 @@ static int sync_ptr1(snd_pcm_hw_t *hw, unsigned
> > > > > int flags) SYSMSG("SNDRV_PCM_IOCTL_SYNC_PTR failed");
> > > > >                 return err;
> > > > >         }
> > > > > +       new_hwptr = hw->sync_ptr->s.status.hw_ptr;
> > > > > +       new_applptr = hw->sync_ptr->c.control.appl_ptr;
> > > > > +       printf("sync_ptr1: %ld(%ld), %ld(%ld)\n",
> > > > > +              new_hwptr, new_hwptr - old_hwptr,
> > > > > +              new_applptr, new_applptr - old_applptr);
> > > > >         return 0;
> > > > >  }
> > > > >  
> > 
> > With sync_ptr I cannot reproduce the very large numbers. Here's a typical log. 
> > (Attached).
> 
> 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).


Takashi
-------------- next part --------------
A non-text attachment was scrubbed...
Name: alsa-time-test.c
Type: application/octet-stream
Size: 5884 bytes
Desc: not available
Url : http://mailman.alsa-project.org/pipermail/alsa-devel/attachments/20090303/78bd08d9/attachment.dll