Repository navigation
[BUG] pipeline will interact with each other in HDA mode #854
Description
Describe the bug
This issue can occur when 2 pipeline playback are running in different terminals, terminating one of them will cause another pipeline stop with I/O error.
To Reproduce
- open two terminals and do playback on each terminal with different pcm device.
terminal 1 headset playback: aplay -Dhw:0,0 -f dat -c 2 audio.wav
terminal 2 HDMI playback: aplay -Dhw:0,2 -f dat -c 2 audio.wav - press ctl+c to stop HDMI playback, then check the status of the another one.
- At least use one HDA pcm device to do the playback.
Expected behavior
no interaction between each pipeline.
Impact
terminating one of them will cause another pipeline stop with I/O error.
Environment
- sof-master: 0c9326
- tplg: sof-whl-rt5682.tplg
- kernel-sof-dev: 90860
- platform: WHL-I2S
- Reproducibility Rate: 100%
Screenshots or console output
$ aplay -Dhw:0,0 -f dat -c 2 test.wav
Playing WAVE 'test.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
underrun!!! (at least 0.047 ms long)
aplay: pcm_write:2011: write error: Input/output error
dmesg
no observes errors.
sof-logger
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 VOLUME 27044583.385417 27044584.000000 src/audio/volume.c:465 volume_copy() error: source component buffer has not enough data available
0 1 PIPE 27044804.479167 221.093750 src/audio/pipeline.c:681 pipeline_copy() error: ret = -5, start->comp.id = 1, dir = 1
0 1 PIPE 1.5 27044811.041667 6.562500 src/audio/pipeline.c:789 pipeline_xrun_recover()
0 1 DMA 27045177.395833 366.354156 intel/cavs/hda-dma.c:279 hda-dmac: 5 wait for buffer full timeout
0 1 HOST 27045183.958333 6.562500 src/audio/host.c:792 host_copy() error: dma_copy() failed, ret = 4294967234
0 1 PIPE 27045189.947917 5.989583 src/audio/pipeline.c:681 pipeline_copy() error: ret = -62, start->comp.id = 4, dir = 1
0 1 PIPE 1.5 27045196.562500 6.614583 src/audio/pipeline.c:789 pipeline_xrun_recover()
0 1 COMP 27045209.479167 12.916667 rc/audio/component.c:201 comp_set_state() error: wrong state = 5, COMP_TRIGGER_PREPARE
0 1 PIPE 27045215.364583 5.885417 src/audio/pipeline.c:365 pipeline_prepare() error: ret = -22,dev->comp.id = 0
0 1 PIPE 1.5 27045221.614583 6.250000 src/audio/pipeline.c:796 pipeline_xrun_recover() error: pipeline_prepare() failed, ret = -22
0 1 PIPE 1.5 27045227.239583 5.625000 src/audio/pipeline.c:865 pipeline_task(): xrun recover failed! pipeline will be stopped!
logger-t :
0 2 BUFFER 27043352.395833 1244.635376 src/audio/buffer.c:127 comp_update_buffer_produce(), no bytes to produce
0 2 DMA 27043357.031250 4.635417 intel/cavs/hda-dma.c:627 hda-dmac: 5 channel 0 -> stop
0 1 VOLUME 27044583.385417 1226.354126 src/audio/volume.c:465 volume_copy() error: source component buffer has not enough data available
0 2 COMP 27044589.270833 5.885417 of/audio/component.h:700 comp_underrun(), ((dev->comp.id << 16) | source->avail) = 65536, ((min_bytes << 16) | copy_bytes) = 0
0 2 PIPE 1.5 27044593.281250 4.010417 src/audio/pipeline.c:540 pipeline_trigger()
0 2 HOST 27044597.447917 4.166667 src/audio/host.c:283 host_trigger()
0 2 DMA 27044602.083333 4.635417 intel/cavs/hda-dma.c:627 hda-dmac: 5 channel 0 -> stop
0 2 VOLUME 27044606.562500 4.479167 src/audio/volume.c:434 volume_trigger()
0 2 DAI 1.4 27044610.729167 4.166667 src/audio/dai.c:528 dai_comp_trigger(), command = 8
0 2 DAI 1.4 27044614.635417 3.906250 src/audio/dai.c:586 dai_comp_trigger(), XRUN
0 2 DAI 1.4 27044618.125000 3.489583 src/audio/dai.c:592 dai_comp_trigger(), PAUSE/STOP
0 2 DMA 27044621.770833 3.645833 src/drivers/dw/dma.c:456 dw_dma_stop(): dma 0 channel 0 stop
0 2 SSP 27044630.520833 8.750000 ers/intel/cavs/ssp.c:812 ssp_trigger() cmd 0
0 2 SSP 27044793.333333 162.812500 ers/intel/cavs/ssp.c:793 ssp_stop(), TX stop
0 2 SSP 27044798.177083 4.843750 ers/intel/cavs/ssp.c:802 ssp_stop(), SSP port disabled
0 1 PIPE 27044804.479167 6.302083 src/audio/pipeline.c:681 pipeline_copy() error: ret = -5, start->comp.id = 1, dir = 1
0 1 PIPE 1.5 27044811.041667 6.562500 src/audio/pipeline.c:789 pipeline_xrun_recover()
0 2 PIPE 1.5 27044816.197917 5.156250 src/audio/pipeline.c:358 pipeline_prepare()
0 2 HOST 27044820.312500 4.114583 src/audio/host.c:635 host_prepare()
0 2 COMP 27044824.166667 3.854167 rc/audio/component.c:136 comp_set_state(), state already set to 3
0 2 PIPE 1.5 27044828.333333 4.166667 src/audio/pipeline.c:540 pipeline_trigger()
0 2 HOST 27044832.395833 4.062500 src/audio/host.c:283 host_trigger()
0 2 DMA 27044836.562500 4.166667 intel/cavs/hda-dma.c:533 hda-dmac: 5 channel 0 -> start
0 2 DMA 27044840.625000 4.062500 intel/cavs/hda-dma.c:369 hda-dmac: 5 channel 0 -> enable
0 2 VOLUME 27044898.958333 58.333332 src/audio/volume.c:434 volume_trigger()
0 2 DAI 1.4 27044902.916667 3.958333 src/audio/dai.c:528 dai_comp_trigger(), command = 1
0 2 DAI 1.4 27044906.770833 3.854167 src/audio/dai.c:539 dai_comp_trigger(), START
0 1 DMA 27045177.395833 270.625000 intel/cavs/hda-dma.c:279 hda-dmac: 5 wait for buffer full timeout
0 1 HOST 27045183.958333 6.562500 src/audio/host.c:792 host_copy() error: dma_copy() failed, ret = 4294967234
0 1 PIPE 27045189.947917 5.989583 src/audio/pipeline.c:681 pipeline_copy() error: ret = -62, start->comp.id = 4, dir = 1
0 1 PIPE 1.5 27045196.562500 6.614583 src/audio/pipeline.c:789 pipeline_xrun_recover()
0 2 PIPE 1.5 27045201.718750 5.156250 src/audio/pipeline.c:358 pipeline_prepare()
0 2 HOST 27045205.729167 4.010417 src/audio/host.c:635 host_prepare()
0 1 COMP 27045209.479167 3.750000 rc/audio/component.c:201 comp_set_state() error: wrong state = 5, COMP_TRIGGER_PREPARE
0 1 PIPE 27045215.364583 5.885417 src/audio/pipeline.c:365 pipeline_prepare() error: ret = -22,dev->comp.id = 0
0 1 PIPE 1.5 27045221.614583 6.250000 src/audio/pipeline.c:796 pipeline_xrun_recover() error: pipeline_prepare() failed, ret = -22
0 1 PIPE 1.5 27045227.239583 5.625000 src/audio/pipeline.c:865 pipeline_task(): xrun recover failed! pipeline will be stopped!
0 2 IPC 29281219.739583 2235992.500000 src/ipc/handler.c:480 ipc: comp 0 -> trigger cmd 0x50000
0 2 PIPE 1.5 29281224.739583 5.000000 src/audio/pipeline.c:540 pipeline_trigger()
0 2 HOST 29281229.322917 4.583333 src/audio/host.c:283 host_trigger()
0 2 DMA 29281234.010417 4.687500 intel/cavs/hda-dma.c:627 hda-dmac: 5 channel 0 -> stop
0 2 VOLUME 29281238.854167 4.843750 src/audio/volume.c:434 volume_trigger()
0 2 DAI 1.4 29281243.177083 4.322917 src/audio/dai.c:528 dai_comp_trigger(), command = 0
0 2 DAI 1.4 29281247.083333 3.906250 src/audio/dai.c:592 dai_comp_trigger(), PAUSE/STOP
0 2 DMA 29281251.041667 3.958333 src/drivers/dw/dma.c:456 dw_dma_stop(): dma 0 channel 0 stop
0 2 SSP 29281257.760417 6.718750 ers/intel/cavs/ssp.c:812 ssp_trigger() cmd 0
0 2 SSP 29281421.354167 163.593750 ers/intel/cavs/ssp.c:802 ssp_stop(), SSP port disabled
0 2 IPC 29281749.166667 327.812500 src/ipc/handler.c:369 ipc: comp 0 -> free
0 2 PIPE 1.5 29281753.802083 4.635417 src/audio/pipeline.c:583 pipeline_reset()
0 2 HOST 29281757.968750 4.166667 src/audio/host.c:699 host_reset()
0 2 DMA 29281762.135417 4.166667 intel/cavs/hda-dma.c:627 hda-dmac: 5 channel 0 -> stop
0 2 VOLUME 29281769.322917 7.187500 src/audio/volume.c:601 volume_reset()
Activity
keqiaozhang commentedon Apr 22, 2019
@Jiangxinx @ClarexZhou
Could you please help to verify this issue on other HDA platform?
ClarexZhou commentedon Apr 22, 2019
Behavior is different on CML.
No interaction between Dhw:0,0 and Dhw:0,3
Only no audio output when start aplay on Dhw:0,1 during playing on Dhw:0,0.
No interaction when press ctl+c to stop one.
Environment
Kernel Repo: https://github.com/RanderWang/linux/commits/cml-validation-20190422
Made from: RanderWang/linux@9086043 [thesofproject/linux: topic/sof-dev]
+RanderWang/linux@c105b1b
+RanderWang/linux@ffecddc
+RanderWang/linux@3b917aa
+RanderWang/linux@6f928a3
+RanderWang/linux@a916d2d
+RanderWang/linux@694599b
+RanderWang/linux@a43379d
+RanderWang/linux@d36ed40
+RanderWang/linux@9b3bd71
+RanderWang/linux@e852311
+RanderWang/linux@8f30111
+RanderWang/linux@95cd082
Firmware Repo :https://github.com/bardliao/sof/tree/whl-daliy-20190422
Made from: bardliao/linux@0c93261
Topology: Same as above SOF repo
wenqingfu commentedon Apr 23, 2019
@keqiaozhang can you please help to verify if this issue can be reproduced on I2S platform? thanks!
keqiaozhang commentedon Apr 24, 2019
@wenqingfu , I tried to reproduce this issue on GLK before, but it's blocked by #828 , HDMI is not working.
I just tested it again with PR #834 on GLK, this issue can be reproduced. The reproducibility rate is about 20% and IPC timed out when TRIG_START, but audio is still working in the next run.
trace log:
dmesg.log
logger.log
logger-t.log
Test recipe:
kernel: sof-dev/2e9456 +PR #834
sof/tplg: master/e4c1651
stevyan commentedon Apr 24, 2019
Summary
Not reproduce on APL UP2 pcm512x
Step
Actual Result
No error occurred.
Test recipe
Date: 2019-04-24
sof (master): e4c1651
kernel (topic/sof-dev): 2e94569
topology: sof-apl-pcm512x.tplg
libinyang commentedon Apr 24, 2019
Clair's bug is narrowed down to codec issue. As per discussion we can lower its priority.
It is different from Keqiao's bug. Clair, could you please open a new issue for it?
stevyan commentedon Apr 24, 2019
Summary
"write error: Input/output error" occurred on APL UP2 pcm512x
Step
aplay -Dhw:0,2 -f s16_le -r 48000 -c 2 /dev/zeroActual Result
Test recipe
Date: 2019-04-24
sof (master): e4c1651
kernel (topic/sof-dev): 2e94569
topology: sof-apl-pcm512x.tplg
dmesg log
plbossart commentedon Apr 24, 2019
Can we have confirmation that the two outputs work in isolation and the issues only show up when the two outputs are used concurrently.
keqiaozhang commentedon Apr 25, 2019
Yes, the two outputs work in isolation and the issue only can be reproduced when two outputs are used concurrently.
I also tested the following scenario on GLK, there're two TYPE-C connectors, so we can do playback on these 2 ports via the converters.
Steps:
Dmesg:
trace:
dmesg.log
logger-t.log
Test recipe:
kernel: sof-dev/2e9456 +PR #834 (to fix the HDMI/DP playback issue)
sof/tplg: master/e4c1651
1 remaining item
ClarexZhou commentedon Apr 26, 2019
@libinyang CML issue is split and track on #874
wenqingfu commentedon May 28, 2019
quote @keqiaozhang in thesofproject/sof#1354 (comment) , "these PRs can fix issue #854"
stevyan commentedon May 30, 2019
Error doesn't occurred based on CFL RVP HDA
Test recipe
Date: 2019-05-30
sof (master): 92fc706
kernel (topic/sof-dev): 80a2cb8
topology: sof-hda-general.tplg
Jiangxinx commentedon May 30, 2019
APL UP2 pcm512x & APL UP2 nocodec daily test
Not reproduce when testing HDMI and HDA:
Still occurre "write error: Input/output error" when testing Media Playback and HDA:
Result of testing Media Playback and HDA
Terminal A: write error: Input/output error
Terminal B: underrun, and then "write error: Input/output error"
Test recipe
Date: 2019-05-30
sof (master): 92fc706
kernel (topic/sof-dev): 80a2cb8
topology: sof-apl-pcm512x.tplg & sof-apl-nocodec.tplg
Dmesg
sof-logger
kv2019i commentedon Jun 4, 2019
@wenqingfu Ack, looking at multiple multi-stream cases, I can take a look at this as well.
kv2019i commentedon Jun 6, 2019
Analyzed and moved to firmware as thesofproject/sof#1526
We can keep this open until FW confirms.
@Jiangxinx please add more info to the FW bug if nocodec test scenario can be repeated on other platforms than APL
kv2019i commentedon Jun 6, 2019
I could not reproduce the issues with nocodec mode on WHL. But nocdec mode issue on APL seems clear.
UPDATE: this only happens on topologies with a mixer on the path, explains why I didn't see this on WHL at least yet (see more in the FW bug).
kv2019i commentedon Jul 2, 2019
@keqiaozhang Can you confirm this is fixed now and close the bug if yes? The bug is now fixed in firmware ( thesofproject/sof#1526 ).
YvonneYang2 commentedon Jul 3, 2019
Issue not reproduced with test recipe as below, so close it.
Test recipe:
Firmware: 357e47c https://github.com/thesofproject/sof/commits/master
Kernel: 6ec3295 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: sof-glk-da7219.tplg