Repository navigation
[BUG] ipc timed out for 0x13000004|GLB_SET_PIPELINE_STATE on ADLP-NOCODEC #8072
Description
Describe the bug
Observed this issue in CI daily test, this issue happened when checking capture 100 times. But this issue cannot be reproduced manually and there's no error in mtrace.
** dmesg**
[ 2129.087779] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13000003|0x1: GLB_SET_PIPELINE_STATE [data size: 12]
[ 2129.088193] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x1: GLB_SET_PIPELINE_STATE
[ 2129.088290] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13000003|0x1: GLB_SET_PIPELINE_STATE [data size: 12]
[ 2129.088294] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13000004|0x1: GLB_SET_PIPELINE_STATE [data size: 12]
[ 2129.594030] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc timed out for 0x13000004|0x1
[ 2129.594355] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Attempting to prevent DSP from entering D3 state to preserve context
[ 2129.594365] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump start ]------------
[ 2129.594393] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda irq intsts 0x00000000 intlctl 0xc0000000 rirb 00
[ 2129.594404] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 2129.594431] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Host IPC initiator: 0x93000004|0x1|0x0, target: 0x0|0x0|0x0, ctl: 0x3
[ 2129.594442] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump end ]------------
[ 2129.594450] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump start ]------------
[ 2129.594457] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
[ 2129.594464] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: fw_state: SOF_FW_BOOT_COMPLETE (7)
[ 2129.594487] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0x00000005: module: ROM, state: FW_ENTERED, running
[ 2129.594553] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: extended rom status: 0x5 0x0 0x0 0x0 0x0 0x0 0x0 0x1
[ 2129.594560] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump end ]------------
[ 2129.594618] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to set final state 4 for all pipelines
[ 2129.594631] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
[ 2129.594647] kernel: DMIC Raw: ASoC: trigger FE cmd: 1 failed: -110
To Reproduce
~/sof-test/test-case/check-capture.sh -d 1 -l 100 -r 1
Reproduction Rate
Only happened once in CI, no reproductions so far.
Environment
- Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
- Kernel: {3f9245260d0ae74031839a925c7965ac710fe459}
- SOF: {1f047fe}
- Name of the topology file
- Topology: {avs-tplg/sof-adl-nocodec.tplg}
- Name of the platform(s) on which the bug is observed.
- Platform: {ADLP_RVP_NOCODEC_IPC4ZPH}
Activity
keqiaozhang commentedon Aug 24, 2023
Observed this issue on TGLH_SKU0A70_HDA_IPC4ZPH. Inner test ID:30594. The error is the same as ADLP_RVP_NOCODEC_IPC4ZPH.
keqiaozhang commentedon Aug 25, 2023
Changing the priority to P1 due to this issue occurring on different platforms every day.
kv2019i commentedon Aug 25, 2023
Having trouble to reproduce this locally. Have tried a also a few older/newer kenrels and firmware, plus the latest of both, but so far no luck. Will continue attempt to reproduce (as logs in the CI cases don't really reveal much).
lgirdwood commentedon Aug 28, 2023
@kv2019i its' possible we have some loops iterating over HW IP state changes (e.g. in Zephyr driver for clocks, PM etc). @abonislawski and I discussed and we need to add some time outs with legging to help undcover correctly log these issues.
kv2019i commentedon Aug 29, 2023
Still no luck to reproduce this locally. Will try on more machines.
lgirdwood commentedon Aug 30, 2023
@keqiaozhang do you think this issue is only showing via CI automated testing only ? i.e. manual test is too slow to reporduce ?
kv2019i commentedon Aug 31, 2023
Looking back at our Intel daily tests, this was last seen on the 25th Aug daily, and on a sof-hda-generic-4ch tplg system (not nocodec like this bug was originally). This does seem to occur with dmic, so potentially any tplg with the dmics could trigger this.
keqiaozhang commentedon Sep 1, 2023
This issue occurred three times in ci testing, I cannot manually reproduce it either.
mengdonglin commentedon Sep 11, 2023
@fredoh9 also observed this issue with SOF v2.7-rc1
on TGLU_UP_HDA (sh-tglu-up-hda-01). First failure is check-capture-300times.sh (31/300). But he couldn't manually reproduce this issue on the same device and another pne.
keqiaozhang commentedon Oct 10, 2023
Observed this issue again on TGLU_RVP_NOCODEC-cavs2_5-ipc4-nocodec. Inner test ID: 32810.
fredoh9 commentedon Oct 16, 2023
Reproduced today,
planresultdetail/33110?model=ADLP_RVP_NOCODEC-cavs2_5-ipc4-nocodec&testcase=check-capture-50rounds
fredoh9 commentedon Oct 19, 2023
Reproduced today again,
Intel internal daily test: planresultdetail/33322?model=ADLP_RVP_NOCODEC-cavs2_5-ipc4-nocodec&testcase=check-capture-50rounds
mengdonglin commentedon Nov 8, 2023
Reproduced on ww41.4 https://sof-ci.ostc.intel.com/#/result/planresultdetail/32914
and ww42.4 https://sof-ci.ostc.intel.com/#/result/planresultdetail/33322
Not reproduced in ww43, ww44, ww45 (till ww45.3) FYI @keqiaozhang @fredoh9 @kv2019i @RanderWang
keqiaozhang commentedon Nov 16, 2023
This issue cannot be reproduced in CI. Closing this bug.