Repository navigation
[BUG][IPC4] ipc timed out for 0x46010002|0x1000003 MOD_UNBIND on TGLU_UP_HDA_IPC4ZPH #6503
Description
Describe the bug
After more fixes are merged, most of IPC4 issues have been fixed. But we still have some low reproduction rate errors exist.
In today's IPC4 tests(17059), we found a new type of IPC4 times out 0x46010002|0x1000003 MOD_UNBIND on TGLU_UP_HDA_IPC4ZPH when testing multiple-pipeline-all-25.sh. The reproduction rate is less than 10%.
DMESG
[ 3315.832259] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13060002|0x0: GLB_SET_PIPELINE_STATE
[ 3315.832490] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 3315.832504] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13060002|0x0: GLB_SET_PIPELINE_STATE
[ 3315.832531] kernel: snd_sof_intel_hda_common:ipc4_hda_dai_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: cmd=0 dai Analog CPU DAI direction 0
[ 3315.832534] kernel: snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 7 state 3
[ 3315.832539] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46010002|0x1000003: MOD_UNBIND
[ 3316.337121] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc timed out for 0x46010002|0x1000003
[ 3316.337235] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: preventing DSP entering D3 state to preserve context
[ 3316.337238] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump start ]------------
[ 3316.337256] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda irq intsts 0x00000000 intlctl 0xc0000000 rirb 00
[ 3316.337261] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 3316.337282] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Host IPC initiator: 0xc6010002|0x1000003|0x0, target: 0x0|0x0|0x80000000, ctl: 0x3
[ 3316.337287] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump end ]------------
[ 3316.337291] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump start ]------------
[ 3316.337294] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
[ 3316.337297] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: fw_state: SOF_FW_BOOT_COMPLETE (6)
[ 3316.337305] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0x00000005: module: ROM, state: FW_ENTERED, running
[ 3316.337336] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: extended rom status: 0x5 0x0 0x0 0x0 0x0 0x0 0x0 0x1
[ 3316.337339] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump end ]------------
[ 3316.337346] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to unbind modules mixin.1.1 -> mixout.2.1
[ 3316.337354] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x12080000|0x0: GLB_DELETE_PIPELINE
[ 3316.841126] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc timed out for 0x12080000|0x0
[ 3316.841138] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
[ 3316.841148] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to free pipeline widget pipeline.1
[ 3316.841156] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to free connected widgets
[ 3316.841166] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -110
MTRACE
[ 13.144000] <inf> ipc: rx : 0x93080003|0x0
[ 13.144000] <inf> pipe: pipe:8 0x0 pipe trigger cmd 2
[ 13.145000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 384, possible glitch
[ 13.145000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): nothing to copy
[ 13.145000] <err> copier: comp:8 0x40008 failed to find dai comp or sink pipeline not running.
[ 13.145000] <inf> ll_schedule: task complete 0xbe09d700 0x20240U
[ 13.145000] <inf> ll_schedule: num_tasks 8 total_num_tasks 8
[ 13.145000] <inf> ipc: rx : 0x93020003|0x0
[ 13.145000] <inf> pipe: pipe:2 0x0 pipe trigger cmd 2
[ 13.146000] <err> hda_dma: hda_dma_link_check_xrun(): underrun detected
[ 13.146000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 384, possible glitch
[ 13.146000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): nothing to copy
[ 13.146000] <err> copier: comp:2 0x40002 failed to find dai comp or sink pipeline not running.
[ 13.146000] <inf> ll_schedule: task complete 0xbe090340 0x20240U
[ 13.146000] <inf> ll_schedule: num_tasks 7 total_num_tasks 7
[ 13.146000] <inf> ipc: rx : 0x93020003|0x0
[ 13.146000] <inf> ipc: rx : 0x93040003|0x0
[ 13.146000] <inf> pipe: pipe:4 0x0 pipe trigger cmd 2
[ 13.147000] <wrn> dai_comp: comp:3 0x40003 dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 384, possible glitch
[ 13.147000] <wrn> dai_comp: comp:3 0x40003 dai_copy(): nothing to copy
[ 13.147000] <err> hda_dma: hda_dma_link_check_xrun(): underrun detected
[ 13.147000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 384, possible glitch
[ 13.147000] <wrn> dai_comp: comp:1 0x40001 dai_copy(): nothing to copy
[ 13.147000] <err> copier: comp:4 0x40004 failed to find dai comp or sink pipeline not running.
[ 13.147000] <inf> ll_schedule: task complete 0xbe0929c0 0x20240U
[ 13.147000] <inf> ll_schedule: num_tasks 6 total_num_tasks 6
To Reproduce
/sof-test/test-case/multiple-pipeline.sh -f p -c 20 -l 25
Reproduction Rate
less than10%
Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 30db6e2dc6e4
SOF Branch: main
SOF Commit: 87bd3d628b29
Zephyr Commit: ed661a6c6909
Platform:TGLU_UP_HDA_IPC4ZPH
TPLG:cavs-mixin-mixout-hda.tplg
Activity
keqiaozhang commentedon Nov 4, 2022
Observed this issue on TGLU_RVP_SDW_IPC4ZPH today. Daily test ID:17310
keqiaozhang commentedon Nov 29, 2022
Observed this issue again on TGLU_UP_HDA_IPC4ZPH. Inner test ID:18224.
But hard to reproduce it manually. I tried hundreds of times, but no reproductions.
keqiaozhang commentedon Feb 20, 2023
This bug is no longer exists in CI. Closing.