[BUG][SDW][CML-H]" IPC timed out for 0x60050000 size 12" occured when paplay0,0(RT711) after s3 . #1622
Description
Describe the bug
Firstly disable master and sof runtime PM status via “options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x1”.
" IPC timed out for 0x60050000 size 12" occured when paplay0,0. Need reboot to recover.
To Reproduce
1.Boot up system.
2.Run "paplay wav/48California_Dreaming.wav -vvv" via headset0,0
3.Run "sudo rtcwake -m mem -s 15"
4.Run "Parecord 22.wav -vvv" via Dmic0,4
5.Run "paplay wav/48California_Dreaming.wav -vvv" via headset0,0
6.Run "sudo rtcwake -m mem -s 15"
Reproduce rate
5/10
Expected result
Paplay/Parecord should be normally, no error occured.
Actual result
"ipc timed out for 0x60050000 size 12" occured when paplay/parecord.
dmesg
[ 108.904236] Headphone: ASoC: post trigger FE Headphone cmd 1
[ 108.904238] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 108.904752] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x24001e successful
[ 108.904754] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 108.904910] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 108.904924] Headphone: ASoC: pre trigger FE Headphone cmd 0
[ 108.904925] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 108.904927] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 109.407318] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60050000 size 12
[ 109.407326] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 109.407333] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 109.407485] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 109.407500] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 109.407504] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 109.407513] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 109.407517] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 109.408046] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x240000 successful
[ 109.408054] Headphone: ASoC: trigger FE cmd: 0 failed: -110
[ 109.408075] Headphone: ASoC: prepare FE Headphone
[ 109.408123] SDW0-Playback: ASoC: BE SDW0-Playback event 1 dir 0
[ 109.408205] Headphone: ASoC: post trigger FE Headphone cmd 1
[ 109.408210] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 109.408772] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x24001e successful
[ 109.408781] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 109.911326] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60040000 size 12
[ 109.911334] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 109.911344] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 109.911496] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 109.911510] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 109.911514] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 109.911534] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 109.911538] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 109.911544] Headphone: ASoC: trigger FE cmd: 1 failed: -110
[ 109.911550] Headphone: ASoC: pre trigger FE Headphone cmd 0
[ 109.911556] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 109.911562] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 110.415431] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60050000 size 12
[ 110.415439] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 110.415454] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 110.415605] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 110.415619] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 110.415622] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 110.415632] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 110.415635] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 110.416272] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x240000 successful
[ 110.416290] Headphone: ASoC: trigger FE cmd: 0 failed: -110
[ 110.416382] Headphone: ASoC: prepare FE Headphone
[ 110.416437] SDW0-Playback: ASoC: BE SDW0-Playback event 1 dir 0
[ 110.416534] Headphone: ASoC: post trigger FE Headphone cmd 1
[ 110.416543] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 110.417084] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x24001e successful
[ 110.417094] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 110.919304] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60040000 size 12
[ 110.919312] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 110.919321] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 110.919473] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 110.919488] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 110.919491] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 110.919511] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 110.919515] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 110.919521] Headphone: ASoC: trigger FE cmd: 1 failed: -110
[ 110.919526] Headphone: ASoC: pre trigger FE Headphone cmd 0
[ 110.919533] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 110.919539] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 111.423332] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60050000 size 12
[ 111.423342] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 111.423350] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 111.423502] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 111.423517] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 111.423520] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 111.423531] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 111.423534] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 111.424140] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x240000 successful
[ 111.424160] Headphone: ASoC: trigger FE cmd: 0 failed: -110
[ 111.424262] Headphone: ASoC: prepare FE Headphone
[ 111.424320] SDW0-Playback: ASoC: BE SDW0-Playback event 1 dir 0
[ 111.424398] Headphone: ASoC: post trigger FE Headphone cmd 1
[ 111.424408] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 111.424989] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x24001e successful
[ 111.424996] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 111.927358] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60040000 size 12
[ 111.927365] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 111.927381] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 111.927532] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 111.927547] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 111.927550] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 111.927560] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 111.927563] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 111.927569] Headphone: ASoC: trigger FE cmd: 1 failed: -110
[ 111.927574] Headphone: ASoC: pre trigger FE Headphone cmd 0
[ 111.927580] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 111.927585] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 112.431344] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60050000 size 12
[ 112.431347] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 112.431352] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 112.431490] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 112.431501] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000103 rirb 00
[ 112.431502] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 112.431508] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 112.431510] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 112.432075] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x240000 successful
[ 112.432080] Headphone: ASoC: trigger FE cmd: 0 failed: -110
[ 112.432122] Headphone: ASoC: prepare FE Headphone
[ 112.432151] SDW0-Playback: ASoC: BE SDW0-Playback event 1 dir 0
Sof_error_trace:
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 SA 117197551.302083 117197552.000000 src/lib/agent.c:55 validate(), ll drift detected, delta = 25739
0 1 SA 117218901.979167 21350.677734 src/lib/agent.c:55 validate(), ll drift detected, delta = 25943
0 1 SA 117240152.708333 21250.728516 src/lib/agent.c:55 validate(), ll drift detected, delta = 25973
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: e888e6e +PR #1586
FW: https://github.com/thesofproject/sof/commits/master commit: 98d7ab2
Tplg: Same with FW branch, sof-cml-rt711-rt1308-rt715.tplg
Platform:CML-H Laptop with codec ALC711, 2 x RT1308, RT715 in SDW mode.