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

From: "Lu, Brent" <brent.lu@intel.com>
To: Takashi Iwai <tiwai@suse.de>
Cc: "alsa-devel@alsa-project.org" <alsa-devel@alsa-project.org>,
	"Jaroslav Kysela" <perex@perex.cz>, Takashi Iwai <tiwai@suse.com>,
	Baolin Wang <baolin.wang@linaro.org>,
	Arnd Bergmann <arnd@arndb.de>,
	Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
	Richard Fontana <rfontana@redhat.com>,
	"Thomas Gleixner" <tglx@linutronix.de>,
	paulhsia <paulhsia@chromium.org>,
	"linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
Subject: RE: [PATCH] ALSA: pcm: fix incorrect hw_base increase
Date: Fri, 15 May 2020 09:36:19 +0000	[thread overview]
Message-ID: <BN6PR1101MB213283BD74AA4477B18C96CD97BD0@BN6PR1101MB2132.namprd11.prod.outlook.com> (raw)
In-Reply-To: <s5htv0hoe8p.wl-tiwai@suse.de>

> 
> 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