[TGL][SDW] XRUN causes multiple pipeline capture test to fail #4066

keqiaozhang · 2021-04-09T06:23:15Z

Describe the bug
We found this issue on TGL-chrome SDW device. when running arecord and aplay on several pipelines, it will failed with I/O error, check the dmesg, there's IPC error log: “error: ipc error for 0x60050000 size 12" and also some XRUN errors in dma trace.

To Reproduce

export TPLG=sof-tgl-sdw-max98373-rt5682-4ch.tplg
$ ./sof-test/test-case/multiple-pipeline.sh -f c

Reproduction Rate
100%

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 2338fa4f
SOF Branch: main
SOF Commit: 72121fb
Platform: TGL chromebook SDW

dmesg

[  364.000887] sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg=0x14001e successful
[  364.000896] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[  364.001095] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx succeeded: 0x60040000: GLB_STREAM_MSG: TRIG_START
[  364.043253] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  364.043297] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  364.066976] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  364.067011] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  364.567247] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  364.567286] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  365.067260] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  365.067297] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  365.708354] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 3 dir 1 cmd 0
[  365.708373] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[  365.708579] sof-audio-pci-intel-tgl 0000:00:1f.3: error: ipc error for 0x60050000 size 12
[  365.708594] sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg=0x340000 successful
[  365.708600] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
[  365.708607]  Amplifier Reference: ASoC: trigger FE cmd: 0 failed: -22
[  365.708677] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 3 dir 1
[  365.708683] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[  365.709006] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[  365.709114] sdw_deprepare_stream: subdevice #0-Capture: inconsistent state state 3
[  365.709155] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[  365.709470] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[  365.709485] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 3 dir 1
[  365.855909] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 2 dir 0 cmd 0
[  365.855926] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[  365.856122] sof-audio-pci-intel-tgl 0000:00:1f.3: error: ipc error for 0x60050000 size 12
[  365.856137] sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg=0x140000 successful
[  365.856143] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
[  365.856150]  Speaker: ASoC: trigger FE cmd: 0 failed: -22
[  365.856181] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 2 dir 0
[  365.856188] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[  365.856504] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[  365.859565] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[  365.859763] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[  365.859894] sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 2 dir 0
[  366.567265] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  366.567300] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG

Trace

[1462255136.927083] (        0.000000) c0 dma-trace             src/trace/dma-trace.c:339  ERROR FW ABI 0x3012001 DBG ABI 0x5003000 tag v1.7-rc1-202-g72121fb06c0f src hash 0xfe776052 (ldc hash 0xfe776052)
[   150122.968750] (   150122.968750) c0 dw-dma                 src/drivers/dw/dma.c:1101 ERROR dw_dma_get_data_size(): xrun detected
[   150143.906250] (       20.937500) c0 dai          4.23           src/audio/dai.c:801  ERROR dai_report_xrun(): overrun due to no space available
[   150163.906250] (       20.000000) c0 dai          4.23           src/audio/dai.c:704  ERROR comp_overrun(): sink->free = 0, copy_bytes = 0
[   150269.947917] (      106.041664) c0 pipe         4.24  ....../pipeline-stream.c:168  ERROR pipeline_copy(): ret = -61, start->comp.id = 23, dir = 0
[   150294.062500] (       24.114584) c0 pipe         4.24  ..../pipeline-schedule.c:63   ERROR pipeline_task(): xrun recover failed! pipeline will be stopped!
[   276209.218750] (   125915.156250) c0 dw-dma                 src/drivers/dw/dma.c:1101 ERROR dw_dma_get_data_size(): xrun detected
[   276229.531250] (       20.312500) c0 dai          3.17           src/audio/dai.c:798  ERROR dai_report_xrun(): underrun due to no data available
[   276251.041667] (       21.510416) c0 dai          3.17           src/audio/dai.c:686  ERROR comp_underrun(): dev->comp.id = 17, source->avail = 0, copy_bytes = 0
[   276387.343750] (      136.302078) c0 pipe         3.18  ....../pipeline-stream.c:168  ERROR pipeline_copy(): ret = -61, start->comp.id = 17, dir = 1
[   276411.250000] (       23.906250) c0 pipe         3.18  ..../pipeline-schedule.c:63   ERROR pipeline_task(): xrun recover failed! pipeline will be stopped!
[  1118875.572917] (   842464.312500) c0 dai          4.23     src/audio/component.c:209  ERROR comp_set_state(): wrong state = 1, COMP_TRIGGER_STOP
[  1118898.333333] (       22.760416) c0 pipe         4.24  ....../pipeline-stream.c:205  ERROR pipeline_trigger(): ret = -22, host->comp.id = 19, cmd = 0
[  1118922.968750] (       24.635416) c0 ipc                  src/ipc/handler-ipc3.c:443  ERROR ipc: comp 19 trigger 0x50000 failed -22
[  3828280.312500] (  2709357.250000) c0 host         3.12     src/audio/component.c:209  ERROR comp_set_state(): wrong state = 1, COMP_TRIGGER_STOP
[  3828302.083333] (       21.770834) c0 pipe         3.18  ....../pipeline-stream.c:205  ERROR pipeline_trigger(): ret = -22, host->comp.id = 12, cmd = 0
[  3828324.687500] (       22.604166) c0 ipc                  src/ipc/handler-ipc3.c:443  ERROR ipc: comp 12 trigger 0x50000 failed -22

The text was updated successfully, but these errors were encountered:

XiaoyunWu6666 · 2021-04-09T08:40:46Z

It is related to commit 242d33837f6218c1db1a020d8069cdf85545b277 https://github.com/thesofproject/linux/commit/242d33837f6218c1db1a020d8069cdf85545b277 too
[Please refer to another issue related to this commit : [BUG][TGL][SDW] playback failed on speaker: failed to find SOF DAI for: SDW2 Pin2 thesofproject/linux#2821 ]

To confirm this , I revert commit 242d338 , builded kernel and installed it on ubuntu@sh-tglu-volt-sdw-02 . It appeared that after reverting the commit , multipipeline test worked quite well.

fredoh9 · 2021-04-20T18:40:42Z

Transferred from linux issue. IPC errors are fixed by #4065.
This is XRUN problem from capture pipeline. multi-pipeline test with only playback works fine. renamed the title

lgirdwood · 2021-04-26T15:14:04Z

@fredoh9 can we close ?

fredoh9 · 2021-04-28T21:19:53Z

@lgirdwood #4065 fixes only ipc errors.
However, XRUN issue is duplicated with #3953, #3939.

lgirdwood · 2021-05-13T12:23:31Z

@fredoh9 thanks, can you update and mark the duplicated issues with the duplicated label.

lgirdwood · 2021-06-03T14:54:50Z

@fredoh9 can you link the original duplicate here and assign its owner here. thanks

fredoh9 · 2021-06-04T16:42:47Z

Duplicate of #3953
Original issue is closed.

XiaoyunWu6666 · 2021-06-09T03:48:42Z

still happened on TGLU_VOLT_SDW in internal daily test [id 4457]
so reopen it

mengdonglin · 2021-06-15T09:04:12Z

Comments by @RanderWang : this issue is caused by thesofproject/linux@3a27875.

lgirdwood · 2021-06-15T11:48:37Z

Comments by @RanderWang : this issue is caused by thesofproject/linux@3a27875.

@RanderWang @keqiaozhang does this cause a delay between sending IPC messages ? Can someone confirm ?

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmition was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. According to ASoC framework, be link trigger should be executed before component trigger when starting pipeline and the sequence will be reverse for the stop case. This patch changes sequence to this style. Fixes: Added 30ms turn on/off time delay (3a27875) BugLink: thesofproject/sof#4066 Signed-off-by: Rander Wang <rander.wang@intel.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmition was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. According to ASoC framework, be link trigger should be executed before component trigger when starting pipeline and the sequence will be reverse for the stop case. This patch changes sequence to this style. Fixes: 3a27875 (ASoC: max98373: Added 30ms turn on/off time delay) BugLink: thesofproject/sof#4066 Signed-off-by: Rander Wang <rander.wang@intel.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmition was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 (ASoC: max98373: Added 30ms turn on/off time delay) BugLink: thesofproject/sof#4066 Signed-off-by: Rander Wang <rander.wang@intel.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmition was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 (ASoC: max98373: Added 30ms turn on/off time delay) BugLink: thesofproject/sof#4066 Signed-off-by: Rander Wang <rander.wang@intel.com> Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmission was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 ("ASoC: max98373: Added 30ms turn on/off time delay") BugLink: thesofproject/sof#4066 Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com> Signed-off-by: Rander Wang <rander.wang@intel.com> Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmission was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 ("ASoC: max98373: Added 30ms turn on/off time delay") BugLink: thesofproject/sof#4066 Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com> Signed-off-by: Rander Wang <rander.wang@intel.com> Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Link: https://lore.kernel.org/r/20210625205042.65181-2-pierre-louis.bossart@linux.intel.com Signed-off-by: Mark Brown <broonie@kernel.org>

[ Upstream commit 33c8516 ] On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmission was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 ("ASoC: max98373: Added 30ms turn on/off time delay") BugLink: thesofproject/sof#4066 Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com> Signed-off-by: Rander Wang <rander.wang@intel.com> Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Link: https://lore.kernel.org/r/20210625205042.65181-2-pierre-louis.bossart@linux.intel.com Signed-off-by: Mark Brown <broonie@kernel.org> Signed-off-by: Sasha Levin <sashal@kernel.org>

BugLink: https://bugs.launchpad.net/bugs/1942123 [ Upstream commit 33c8516 ] On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmission was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 ("ASoC: max98373: Added 30ms turn on/off time delay") BugLink: thesofproject/sof#4066 Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com> Signed-off-by: Rander Wang <rander.wang@intel.com> Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Link: https://lore.kernel.org/r/20210625205042.65181-2-pierre-louis.bossart@linux.intel.com Signed-off-by: Mark Brown <broonie@kernel.org> Signed-off-by: Sasha Levin <sashal@kernel.org> Signed-off-by: Kamal Mostafa <kamal@canonical.com> Signed-off-by: Kleber Sacilotto de Souza <kleber.souza@canonical.com>

On TGL platform with max98373 codec the trigger start sequence is fe first, then codec component and sdw link is the last. Recently a delay was introduced in max98373 codec driver and this resulted to the start of sdw stream transmission was delayed and the data transmitted by fw can't be consumed by sdw controller, so xrun happened. Adding delay in trigger function is a bad idea. This patch enable spk pin in prepare function and disable it in hw_free to avoid xrun issue caused by delay in trigger. Fixes: 3a27875 ("ASoC: max98373: Added 30ms turn on/off time delay") BugLink: thesofproject/sof#4066 Reviewed-by: Bard Liao <bard.liao@intel.com> Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com> Signed-off-by: Rander Wang <rander.wang@intel.com> Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Link: https://lore.kernel.org/r/20210625205042.65181-2-pierre-louis.bossart@linux.intel.com Signed-off-by: Mark Brown <broonie@kernel.org>

fredoh9 transferred this issue from thesofproject/linux Apr 20, 2021

fredoh9 changed the title ~~[TGL][SDW] IPC error when doing multiple pipeline test~~ [TGL][SDW] XRUN causes multiple pipeline capture test Apr 20, 2021

fredoh9 changed the title ~~[TGL][SDW] XRUN causes multiple pipeline capture test~~ [TGL][SDW] XRUN causes multiple pipeline capture test to fail Apr 20, 2021

keqiaozhang added bug Something isn't working as expected chrome Chromebooks or ChromeOS SDW SoundWire TGL Applies to Tiger Lake labels Apr 22, 2021

ranj063 mentioned this issue Apr 22, 2021

component: do not reset component status in the case of xrun #4065

Merged

fredoh9 added the duplicate This issue or pull request already exists label May 13, 2021

mengdonglin added the P2 Critical bugs or normal features label May 24, 2021

lgirdwood assigned fredoh9 Jun 3, 2021

fredoh9 closed this as completed Jun 4, 2021

XiaoyunWu6666 added the daily label Jun 9, 2021

XiaoyunWu6666 reopened this Jun 9, 2021

mengdonglin removed the daily label Jun 9, 2021

XiaoyunWu6666 added the Intel Linux Daily tests This issue can be found in internal Linux daily tests label Jun 10, 2021

mengdonglin assigned RanderWang and unassigned fredoh9 Jun 10, 2021

This was referenced Jun 11, 2021

[RFC] ASoC: max98373: power up amp before pipeline start thesofproject/linux#2991

Closed

ASoC: Intel: boards: fix xrun issue on platform with max98373 thesofproject/linux#2997

Merged

plbossart closed this as completed in thesofproject/linux#2997 Jun 22, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[TGL][SDW] XRUN causes multiple pipeline capture test to fail #4066

[TGL][SDW] XRUN causes multiple pipeline capture test to fail #4066

keqiaozhang commented Apr 9, 2021

XiaoyunWu6666 commented Apr 9, 2021 •

edited

fredoh9 commented Apr 20, 2021 •

edited

lgirdwood commented Apr 26, 2021

fredoh9 commented Apr 28, 2021

lgirdwood commented May 13, 2021

lgirdwood commented Jun 3, 2021

fredoh9 commented Jun 4, 2021

XiaoyunWu6666 commented Jun 9, 2021

mengdonglin commented Jun 15, 2021

lgirdwood commented Jun 15, 2021

[TGL][SDW] XRUN causes multiple pipeline capture test to fail #4066

[TGL][SDW] XRUN causes multiple pipeline capture test to fail #4066

Comments

keqiaozhang commented Apr 9, 2021

XiaoyunWu6666 commented Apr 9, 2021 • edited

fredoh9 commented Apr 20, 2021 • edited

lgirdwood commented Apr 26, 2021

fredoh9 commented Apr 28, 2021

lgirdwood commented May 13, 2021

lgirdwood commented Jun 3, 2021

fredoh9 commented Jun 4, 2021

XiaoyunWu6666 commented Jun 9, 2021

mengdonglin commented Jun 15, 2021

lgirdwood commented Jun 15, 2021

XiaoyunWu6666 commented Apr 9, 2021 •

edited

fredoh9 commented Apr 20, 2021 •

edited