On 12 January 2018 at 11:26, Takashi Iwai tiwai@suse.de 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".