Repository navigation
Stress test: simultaneous playback and capture will cause Input/output error #180
Description
The reproducibility is about 30%.
How to reproduce:
- start playback and capture at same time
aplay -D hw:0,0 -r 48000 -f S24_LE -c 2 /dev/zero -d 5 & arecord -D hw:0,0 -c 2 -f S24_LE -r 48000 /dev/null -d 5 - repeat step 1.
environment:
on CNL
sof-dev: 18917b91d619664c4e38b7180ff89bd9c1397758
sof: 5e83da7
soft: fdf3924
tplg file name :
test-ssp0-mclk-0-I2S-volume-s24le-s24le-48k-24000k-nocodec.tplg
log:
dmesg.log
memorywindow.log
rmbox.log
Activity
[-]alsabat "input/output error" using test-ssp0-mclk-0-I2S-volume-s24le-s24le-48k-24000k-nocodec.tplg[/-][+]Stress test: simultaneous playback and capture will cause Input/output error[/+]zhuqingliang commentedon Jul 31, 2018
the reproduce rate is about 15%
tlauda commentedon Jul 31, 2018
No errors/xruns in neither dmesg nor rmbox logs.
Problem should be checked from kernel side.
jocelyn-li commentedon Jul 31, 2018
@zhuqingliang Does this issue only happen on CNL?
zhuqingliang commentedon Aug 1, 2018
the issue also happens when use tplg "test-ssp0-mclk-0-I2S-volume-s16le-s16 le-48k-24000k-nocodec.tplg " on CNL.
On APL , the issues is same as CNL , no errors in demsg log.
On BYT, the issues happens with "ipc timed out" in dmesg log.
BYT log:
dmesg.log
rmbox.log
tlauda commentedon Aug 1, 2018
If we confirmed, that the error isn't coming from the FW, can we move this issue to kernel?
lgirdwood commentedon Aug 1, 2018
@zhuqingliang I can't see any errors on the CNL logs.
@RanderWang on BYT looks like from log that kernel is sending 2 IPC messages at once.
[48194.809293] sof-audio sof-audio: stream_tag 0
[48194.809310] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 1
[48194.809334] sof-audio sof-audio: ipc: send 0x60010000
[48194.809357] sof-audio sof-audio: ipc: send 0x60040000
[48194.809490] sof-audio sof-audio: error: reply expected 0xc got 0x14 bytes
[48194.809509] sof-audio sof-audio: error: ipc error for 0x60040000 size 0xc
[48194.809521] Passthrough: ASoC: trigger FE failed -22
[48194.809528] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 0
[48194.809541] sof-audio sof-audio: ipc: send 0x60050000
[48194.810744] sof-audio sof-audio: error: ipc error for 0x60050000 size 0xc
[48194.810765] Passthrough: ASoC: trigger FE failed -22
[48195.068105] sof-audio sof-audio: ipc rx: 0x90020000 done
[48195.133902] sof-audio sof-audio: error: ipc timed out for 0x60010000 size 0x60
[48195.133958] sof-audio sof-audio: error: unexpected fault 0x90020000 trace 0x60050000
[48195.133971] sof-audio sof-audio: error: waking up any trace sleepers
[48195.134007] sof-audio sof-audio: error: got wrong posn offset 0xffffa08b for PCM -110
[48195.134022] sof-audio sof-audio: ASoC: sof-audio hw params failed: -110
[48195.134037] Passthrough: ASoC: hw_params FE failed -110
keqiaozhang commentedon Aug 2, 2018
Update:
This issue still can be reproduced with latest code base. When input/output error occurs, aplay and arecord will stop immediately, but no ipc timed out or firmware panic error, so you can rerun aplay and arecord.
lgirdwood commentedon Aug 2, 2018
@keqiaozhang can you try this again on BYT after reverting kernel commit 145f6f21fe0d35d02443d921bdb435cf80be8aee.
Can you paste the cmd line console log when the error happens on CNL/APL.
keqiaozhang commentedon Aug 2, 2018
@lgirdwood
After reverting the patch, this issue is hard to reproduce on BYT, I tested it more than 100 times.
But on CNL and APL, this issue still can be reproduced and reproducibility is low.
test@test-CannonLake:~$ aplay -Dhw:0,0 -fS16_LE -c2 -r 48000 /dev/zero -d 3 & arecord -Dhw:0,0 -c2 -r 48000 -fS16_Le /dev/null -d 3
[1] 2216
Recording WAVE '/dev/null' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
Playing raw data '/dev/zero' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
arecord: pcm_read:2103: read error: Input/output error
There're no error message in dmesg or rmbox.
lgirdwood commentedon Aug 7, 2018
@RanderWang looks like locking on HW IPC needs some updates. Can you revert the BYT kernel patch too.
RanderWang commentedon Aug 13, 2018
@lgirdwood I test it with latest code and only find the error: aplay: main:788: audio open error: Device or resource busy.
It is not caused by my patch and I got this bug for a long time. there is a anther error message without my patch.
50 remaining items
wenqingfu commentedon Sep 28, 2018
@ZhendanYang ping?
ZhendanYang commentedon Sep 28, 2018
@wenqingfu
Latest status:
This issue can not reproduce on APL(up2) now, but still exists on CNL. On BYT, even worse, input/output error can lead to ipc error:
[ 133.210279] sof-audio sof-audio: error: ipc error for 0x60010000 size 0x14
[ 133.210322] sof-audio sof-audio: ASoC: sof-audio hw params failed: -22
[ 133.210343] sof-audio sof-audio: pcm: free stream 0 dir 0
[ 133.210373] sof-audio sof-audio: ipc tx: 0x60030000
[ 133.210459] sof-audio sof-audio: ipc tx succeeded: 0x60030000
[ 133.210485] Passthrough: ASoC: hw_params FE failed -22
Test env:
sof master: 299ccbc
sof tool: 60c3937
kernel: sof-dev 51ebd5d
Log:
dmesg-byt.log
dmesg-cnl.log
mengdonglin commentedon Sep 30, 2018
@RanderWang @ZhendanYang @wenqingfu Maybe we can focus on fixing BYT at first?
CNL has no customer interest and will be dropped when WHL and ICL is ready. WHL has no request for I2S but ICL does. So if ICL also has this bug, we can involve firmware engineer to cover ICL.
lgirdwood commentedon Oct 1, 2018
@ZhendanYang this is now 2 different bugs - 1) A FW oops of CNL, 2) a hw_params() failure on BYT. hw_paramas wil return an error if the driver is asking a rate it does not support so please make sure you list the topology and cmd line for any hw_param() failure.
I would close this now and re-open as two different issues, for 1) and 2) above.
mengdonglin commentedon Oct 10, 2018
@ZhendanYang I think we can overlook FW oops on CNL and file a new issue if WHL also has the problem.
And could you close this one and file a new bug for hw_params() failure on BYT?
ZhendanYang commentedon Oct 10, 2018
@mengdonglin BYT is in bad health at this moment and I can't reproduce hw_param() failure or collect error log.
lgirdwood commentedon Nov 8, 2018
@zhuqingliang @ZhendanYang can you try this again with latest master.
dabekjakub commentedon Nov 8, 2018
@lgirdwood I repoduced it on latest master Fw and latest kernel (90eee408aea3f64949c3c095d2a338491ad5c8a4 cros-v4.14-rebase) it is reproducible.
However the timeout itself is not present in fw trace logs.
@tlauda Has also asked to move it to kernel issue list:
lgirdwood commentedon Nov 8, 2018
@dabekjakub ok thanks - @zhuqingliang @ZhendanYang please move this to kernel bug and attach the logs with latest master. Thanks. @RanderWang can you check driver is not sending 2 IPCs at once.
mengdonglin commentedon Nov 9, 2018
Close this issue and will follow up by thesofproject/linux#263