[BUG][Stress] Wait for buffer full timeout issue happens on GLK #1486
Description
Describe the bug
I observed this issue when doing the playback stress test. aplay stopped running with the input/output error but audio is still working for the next run. Checking the error trace, there're some host/pipeline copy errors.
BTW, so far, I can only reproduce this issue on GLK.
To Reproduce
while aplay -Dhw:0,5 -f dat -c 2 audio.wav -d 1; do :; done
Reproduction Rate
The reproduction rate is less than 5%.
Expected behavior
no errors during the playback test.
Impact
aplay stopped running and there were some error traces.
Environment
-
Kernel: https://github.com/lyakh/linux/tree/ipc-timeout
commit d8b5fdd ASoC: SOF: hda: set autosuspend delay for hda bus device -
FW : https://github.com/lyakh/sof/tree/ipc-timeout
commit 47dc14d host: remove duplicate dma_stop() -
Topology: sof-glk-da7219.tplg
-
Platform: GLK/ubuntu18.04
-
Reproducibility Rate: less than 5%
Screenshots or console output
aplay: pcm_write:2051: write error: Input/output error.
dmesg
no obvious errors
logger
memory window is empty, this could be another issue.
./sof-logger -l sof-apl.ldc
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
**logger -t **
0 2 VOLUME 1804126249.218750 37.395832 udio/volume/volume.c:488 volume_trigger()
0 2 DAI 5.31 1804126253.333333 4.114583 src/audio/dai.c:510 dai_comp_trigger(), command = 1
0 2 DAI 5.31 1804126257.083333 3.750000 src/audio/dai.c:521 dai_comp_trigger(), START
0 1 DMA 1804126475.052083 217.968750 intel/cavs/hda-dma.c:290 hda-dmac: 5 wait for buffer full timeout rp 0x0 wp 0x0
0 1 HOST 1804126482.083333 7.031250 src/audio/host.c:794 host_copy() error: dma_copy() failed, ret = 4294967234
0 1 PIPE 1804126487.812500 5.729167 src/audio/pipeline.c:732 pipeline_copy() error: ret = -62, start->comp.id = 31, dir = 1
0 1 PIPE 5.32 1804126494.427083 6.614583 src/audio/pipeline.c:844 pipeline_xrun_recover()
0 2 PIPE 5.32 1804126499.218750 4.791667 src/audio/pipeline.c:352 pipeline_prepare()
0 2 HOST 1804126503.177083 3.958333 src/audio/host.c:638 host_prepare()
0 1 COMP 1804126506.927083 3.750000 rc/audio/component.c:197 comp_set_state() error: wrong state = 5, COMP_TRIGGER_PREPARE
0 1 PIPE 1804126512.500000 5.572917 src/audio/pipeline.c:359 pipeline_prepare() error: ret = -22,dev->comp.id = 27
0 1 PIPE 5.32 1804126518.802083 6.302083 src/audio/pipeline.c:851 pipeline_xrun_recover() error: pipeline_prepare() failed, ret = -22
0 1 PIPE 5.32 1804126524.062500 5.260417 src/audio/pipeline.c:922 pipeline_task(): xrun recover failed! pipeline will be stopped!
0 2 IPC 1805848041.145833 1721517.125000 src/ipc/handler.c:479 ipc: comp 27 -> trigger cmd 0x50000
0 2 PIPE 5.32 1805848053.593750 12.447917 src/audio/pipeline.c:579 pipeline_trigger()
0 2 HOST 1805848057.760417 4.166667 src/audio/host.c:286 host_trigger()
0 2 DMA 1805848062.500000 4.739583 intel/cavs/hda-dma.c:650 hda-dmac: 5 channel 0 -> stop
Activity
wwittbrx commentedon May 29, 2019
Does this issue reproduce on master branch? https://github.com/lyakh/sof/tree/ipc-timeout branch is 3 commits ahead and 11 commits behind. Similar with the kernel branch. I don't feel comfortable spending time reproducing the issue observed on unofficial branches.
Also, can we reproduce the issue on GLK with ChromeOS with https://github.com/thesofproject/linux/tree/topic/cros-sof-v4.14-rebase branch?
keqiaozhang commentedon Jun 3, 2019
@wwittbrx
I just tried the latest kernel sof-dev and firmware master branch on my GLK, this issue can still be reproduced.
Test recipe:
kernel: sof-dev/0a747dc
sof/tplg: master/8901e
platform: GLK-Ubuntu
keqiaozhang commentedon Jun 3, 2019
This issue is easy to reproduce(within ten times) when DEBUG_VERBOSE is enabled in kernel side.
CONFIG_SND_DEBUG_VERBOSE=y
The kernel config file is attached.
linux-sof -config.txt
mrajwa commentedon Jun 3, 2019
@keqiaozhang, I am working on fix for very related "wait for buffer empty" issue. I think this should also cover this problem. I will commit in following days.
wwittbrx commentedon Jun 4, 2019
@keqiaozhang does this happen on different devices for you?
I was unable to reproduce with -D hw:0,0 or -D hw:0,1.
With -D hw:0,5 reproduction is easy.
Either way, I suggest we wait for Marcin's fix and check if it solves our problem.
keqiaozhang commentedon Jun 4, 2019
@wwittbrx
This issue cannot be reproduced on I2S(hw:0,0/hw:0,1). it's easy to reproduce on HDA audio(hw:0,5/hw:0,6)
mrajwa commentedon Jun 5, 2019
@keqiaozhang, have you noticed any dependency on --period-size? Like bigger/smaller values cause this issue to happen more/less frequently?
wwittbrx commentedon Jun 12, 2019
@keqiaozhang I can't reproduce this issue at current master branches
8eb6a78
thesofproject/linux@dd9faef
Can you confirm it on your side?
tlauda commentedon Jun 12, 2019
@keqiaozhang @wwittbrx If you can't reproduce it anymore, you can assume it has been fixed by #1546.
keqiaozhang commentedon Jun 14, 2019
Thanks @tlauda and @wwittbrx
This issue is not reproducible to me, I got 50K iterations pass with latest code base. So this issue can be closed now.
Test recipe:
Kernel: sof-dev/96033e6b
Firmware: master/96a544e6