From mboxrd@z Thu Jan 1 00:00:00 1970 From: Takashi Iwai Subject: Re: Bad PCM stream after a suspend/resume cycle Date: Fri, 12 Jan 2018 19:04:41 +0100 Message-ID: References: Mime-Version: 1.0 (generated by SEMI 1.14.6 - "Maruoka") Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Return-path: Received: from mx2.suse.de (mx2.suse.de [195.135.220.15]) by alsa0.perex.cz (Postfix) with ESMTP id 725FE266B67 for ; Fri, 12 Jan 2018 19:04:42 +0100 (CET) In-Reply-To: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: alsa-devel-bounces@alsa-project.org Sender: alsa-devel-bounces@alsa-project.org To: Mirza Krak Cc: linux-rockchip@lists.infradead.org, alsa-devel@alsa-project.org, Heiko =?UTF-8?B?U3TDvGJuZXI=?= List-Id: alsa-devel@alsa-project.org On Fri, 12 Jan 2018 14:36:45 +0100, Mirza Krak wrote: > > On 12 January 2018 at 11:26, Takashi Iwai wrote: > > On Thu, 11 Jan 2018 10:06:12 +0100, > > Mirza Krak wrote: > >> > >> Hi. > >> > >> I have a quite simple problem really (simple test-case at least). > >> > >> Following describes the test case: > >> > >> $ aplay test.wav > >> > >> # While the .wav is playing suspend the system > >> $ systemctl suspend > >> > >> # When system is resumed I get the following error on my aplay command > >> aplay: pcm_write:2030: write error: File descriptor in bad state > >> > >> I was expecting for the playback to resume. > >> > >> I did some debugging using "aplay" and what I can see that happens > >> before the EBADFD error is that the "writei_func()" returns a positive > >> value once which results in a call to "snd_pcm_wait()" and on the next > >> "writei_func()" call -EBADFD is returned. > >> > >> I would expect a -ESTRPIPE error which should then result in that the > >> PCM stream to be "resumed" (according to documentation at least). I > >> have tried "forcing" a call to "suspend()" on the first write error in > >> aplay after system is resumed and it actually works, kinda. The > >> playback is resumed even-though the "snd_pcm_resume()" call returns an > >> error. > >> > >> I have not worked much with the sound subsystem before and I am having > >> a hard time following all the call paths to see who/what is to blame > >> for this behavior. Maybe it expected to work like this? And I do not > >> know if this is only on my SoC or if this is a generic sound problem. > > > > It's no generic issue but specific to platform / SoC driver > > implementation. > > Thank you for the answer. > > I have done some more digging. > > With the help of the amazing "printf" I was able to capture the below sequence > > [ 124.133306] snd_pcm_common_ioctl [2873]: command=0xc0844123 > [ 124.133307] snd_pcm_common_ioctl [2875] > [ 124.133308] snd_pcm_common_ioctl [2880] > [ 124.133309] snd_pcm_common_ioctl [2886] > [ 124.133313] snd_pcm_ioctl > [ 124.133314] snd_pcm_common_ioctl [2873]: command=0x400c4150 > [ 124.133315] snd_pcm_common_ioctl [2875] > [ 124.133317] snd_pcm_common_ioctl [2880] > [ 124.133318] snd_pcm_common_ioctl [2886] > [ 124.133319] snd_pcm_xferi_frames_ioctl > [ 124.133320] __snd_pcm_lib_xfer > [ 124.133322] __snd_pcm_lib_xfer [2186] > [ 124.133326] __snd_pcm_lib_xfer [2195] > [ 124.133367] wait_for_avail [1851] > [ 124.188805] Freezing user space processes ... > [ 124.188915] wait_for_avail [1906] > [ 124.188917] __snd_pcm_lib_xfer [2257] > [ 124.188919] __snd_pcm_lib_xfer [2262]: xfer: 1523 > [ 124.274008] (elapsed 0.085 seconds) done. > [ 124.283733] OOM killer disabled. > [ 124.287323] Freezing remaining freezable tasks ... (elapsed 0.001 > seconds) done. > [ 124.382438] Rockchip I2S suspend/stop/pause called > [ 124.588929] vdd_cpu: No configuration > [ 124.593028] vdd_gpu: No configuration > [ 124.598441] Disabling non-boot CPUs ... > [ 124.763337] Enabling non-boot CPUs ... > [ 124.768869] CPU1 is up > [ 124.772788] CPU2 is up > [ 124.776722] CPU3 is up > [ 125.496875] rk_gmac-dwmac ff290000.ethernet: init for RGMII > [ 125.771693] usb 1-1: reset high-speed USB device number 2 using dwc2 > [ 126.142175] OOM killer enabled. > [ 126.145679] Restarting tasks ... > [ 126.145897] snd_pcm_ioctl > [ 126.148204] done. > [ 126.154667] snd_pcm_common_ioctl [2873]: command=0xc0844123 > aplay: return writei_func: 1523 > [ 126.154669] snd_pcm_common_ioctl [2875] > aplay: pcm_write:2025: [ 126.154671] snd_pcm_common_ioctl [2880] > EAGAIN: 1523 > aplay: call writei_func > aplay: return writei_func[ 126.154672] snd_pcm_common_ioctl [2886] > : -77 > aplay: pcm_write:2035: write error: File descriptor in ba[ > 126.168420] snd_pcm_ioctl > d state > [ 126.168422] snd_pcm_common_ioctl [2873]: command=0xc0844123 > [ 126.168423] snd_pcm_common_ioctl [2875] > [ 126.168424] snd_pcm_common_ioctl [2880] > [ 126.168425] snd_pcm_common_ioctl [2886] > [ 126.168435] snd_pcm_ioctl > [ 126.168437] snd_pcm_common_ioctl [2873]: command=0xc0844123 > [ 126.168438] snd_pcm_common_ioctl [2875] > [ 126.168439] snd_pcm_common_ioctl [2880] > [ 126.168440] snd_pcm_common_ioctl [2886] > [ 126.168470] snd_pcm_ioctl > [ 126.168472] snd_pcm_common_ioctl [2873]: command=0xc0844123 > [ 126.168473] snd_pcm_common_ioctl [2875] > [ 126.168474] snd_pcm_common_ioctl [2880] > [ 126.168476] snd_pcm_common_ioctl [2886] > [ 126.168478] snd_pcm_ioctl > [ 126.168480] snd_pcm_common_ioctl [2873]: command=0x00004143 > [ 126.168481] snd_pcm_common_ioctl [2875] > [ 126.168482] snd_pcm_common_ioctl [2880] > [ 126.168483] snd_pcm_common_ioctl [2886] > [ 126.168491] snd_pcm_ioctl > [ 126.168493] snd_pcm_common_ioctl [2873]: command=0x00004112 > [ 126.168494] snd_pcm_common_ioctl [2875] > [ 126.168495] snd_pcm_common_ioctl [2880] > [ 126.168496] snd_pcm_common_ioctl [2886] > [ 126.168870] snd_pcm_set_state: state: 0 > [ 126.303963] PM: suspend exit > > The interesting takeaways here are: > > - It seems that it always "freezes" in the __snd_pcm_lib_xfer (I guess > that is expected as my system currently only does a audio playback and > the rest is idle) > - This means that aplay has a write in progress that it will > resume when system is woken > - My hardware does not support "pause", because the DMA does not > support this > - "__snd_pcm_lib_xfer" will return a positive value indicating > "partial write" when system is suspended, guessing due to DMA being > torn down. > - When "aplay" resumes it will get an positive return value on the > write command which will trigger a re-write with the chunk remaining > to write > - And here is my problem I believe, because the stream has been > suspended I am not allowed to write to it again until it has been > restored/recovered, which in turn triggers the -EBADFD error. > > Above maybe is what is expected since there seem to be some limitation > in hardware, but I would greatly appropriate any pointers in how this > should be handled. Is there something that can be done in platform / > SoC code to notify the sound/core to handle this "more > smoothly"(underrun error?) > > or is my only option only to catch the -EBADFD error and restart the > playback "manually". The EBADFD is already indicating a fatal error, and something is wrong in the driver. Basically the driver should suspend the stream via snd_pcm_suspend*() call in the PM resume ops. Most likely your driver misses that. That said, it's specific to your using driver, and you'd need to take a look at that code there. Takashi