RE: [PATCH] ALSA: pcm: fix incorrect hw_base increase

From: Lu, Brent
Date: Fri May 15 2020 - 05:36:26 EST


>
> Updating hw_ptr_jiffies at that code path looks correct, but it still leaves the
> question why this condition happens. It means that the actual hwptr isn't
> changed and yet only jiffies increase significantly; it means that the hardware
> can't report proper pointer, and it should have set
> SNDRV_PCM_INFO_BATCH flag, then the jiffies check is skipped.
>
> With which hardware and under which situation did it happen (and the patch
> fixed)?
>
>
> thanks,
>
> Takashi
>

>From time to time we got questions from google about why sometimes the
snd_pcm_avail() returns a value larger than buffer size. Recently we finally
found reliable reproduce steps: it's on Intel GLK Chromebook Fleex with
SOF firmware. There is a 1/20 chance the audio playback to HDMI fails.

>From the FW side we observe a buffer runderrun, the FW is not able to
recover it for some reason and stops the pipe.

>From the Linux side we see the pos does not increase because the FW stops
receiving data but suddenly the hw_prt is increased by buffer_size (16368).
It could make snd_pcm_avail() reporting a false underrun to the caller like
following log:

2020-05-09T16:08:32.712042+08:00 DEBUG kernel: [ 418.510086] sound pcmC0D5p: pos 96 hw_ptr 96 appl_ptr 4096 avail 12368
2020-05-09T16:08:32.712043+08:00 DEBUG kernel: [ 418.510149] sound pcmC0D5p: pos 96 hw_ptr 96 appl_ptr 6910 avail 9554
...
2020-05-09T16:08:32.883095+08:00 DEBUG kernel: [ 418.680868] sound pcmC0D5p: pos 96 hw_ptr 96 appl_ptr 15102 avail 1362
2020-05-09T16:08:32.883104+08:00 DEBUG kernel: [ 418.681052] sound pcmC0D5p: pos 96 hw_ptr 96 appl_ptr 15102 avail 1362
2020-05-09T16:08:32.883109+08:00 DEBUG kernel: [ 418.681130] sound pcmC0D5p: pos 96 hw_ptr 96 appl_ptr 16464 avail 0
2020-05-09T16:08:32.929330+08:00 DEBUG kernel: [ 418.726515] sound pcmC0D5p: pos 96 hw_ptr 16464 appl_ptr 16464 avail 16368
2020-05-09T16:08:32.929512+08:00 DEBUG kernel: [ 418.727041] sound pcmC0D5p: pos 96 hw_ptr 16464 appl_ptr 16464 avail 16368

Or it could make snd_pcm_avail() returns an invalid number and confuses the
Caller like following log:

2020-05-09T16:08:33.054039+08:00 DEBUG kernel: [ 418.851755] sound pcmC0D5p: pos 96 hw_ptr 16464 appl_ptr 27390 avail 5442
2020-05-09T16:08:33.129552+08:00 DEBUG kernel: [ 418.926491] sound pcmC0D5p: pos 96 hw_ptr 32832 appl_ptr 27390 avail 21810
2020-05-09T16:08:33.131746+08:00 ERR cras_server[1907]: pcm_avail returned frames larger than buf_size: sof-glkda7219max: :0,5: 21810 > 16368

I've submitted a patch to fix the issue in SOF side. However, I think it's also good
to fix the incorrect hw_base increasement in Linux side.

https://github.com/thesofproject/sof/pull/2926


Regards,
Brent