Repository navigation
[BUG][s2idle] IPC error after pause_push/S0 idle/resume/pause_release #1387
Description
Describe the bug
Pause aplay/arecord then enter s3, after wake up and resume aplay/arecord ,it tips"ipc error for 0x60040000 size 12"
All of headset /HDMI/DP/Dmic/can reproduce it.
To Reproduce
1.sudo reboot
2.aplay -Dhw:0,0 -fs16_le -c2 -r 48000 -vv -i wav/48California_Dreaming.wav or arecord -Dhw:0,0 -r48000 -c2 -fs16_le s30.wav -vv -i
3.press space key to pause audio
4.sudo rtcwake -m mem -s 10 to suspend
5.after wake up press space key to resume audio
Reproduction Rate
5/5
tried 5times can reproduced 5times
Expected behavior
the audio can resume normally
Impact
What impact does this issue have on your progress (e.g., annoyance, showstopper)
Environment
platform: ICL-RVP in HDA mode
Firmware: 78b022b https://github.com/thesofproject/sof/commits/master
Kernel: 34562a4 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-hda-generic-4ch.tplg same as firmware
Logger_error
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 SA 57856563.854167 57856564.000000 src/lib/agent.c:57 validate(), ll drift detected, delta = 41555
0 1 SA 71894560.052083 14037996.000000 src/lib/agent.c:57 validate(), ll drift detected, delta = 41497
0 1 COMP 155431871.250000 83537312.000000 rc/audio/component.c:119 comp_set_state() error: wrong state = 4, COMP_TRIGGER_START
0 1 IPC 155431881.197917 9.947917 src/audio/pipeline.c:679 pipeline_trigger() error: ret = -22, host->comp.id = 1, cmd = 1
0 1 IPC 155431892.447917 11.250000 src/ipc/handler.c:489 ipc: comp 1 trigger 0x40000 failed -22
Dmesg
69.446640] PM: suspend exit
[ 71.068906] asix 3-8.1:1.0 enx000ec6bc48cf: link up, 100Mbps, full-duplex, lpa 0x43E1
[ 78.022246] sof-audio-pci 0000:00:1f.3: In hda_link_pcm_trigger cmd=1
[ 78.022249] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 78.022777] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x2014001e successful
[ 78.022779] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 78.022904] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x60040000 size 12
[ 78.022908] HDA Analog: ASoC: trigger FE cmd: 1 failed: -22
[ 78.022909] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 78.022911] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 78.022994] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 78.023532] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x140000 successful
[ 78.023535] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 78.023619] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 78.023622] sof-audio-pci 0000:00:1f.3: In hda_link_pcm_trigger cmd=0
[ 78.023627] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 78.023729] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 78.631104] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 78.631135] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 78.631364] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 78.631468] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
[ 78.985462] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 78.985502] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 79.485437] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 79.485477] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 80.855685] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[ 80.893830] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 80.894047] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 80.894111] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[ 80.894135] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[ 80.894154] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[ 80.894221] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at 00000044
Activity
dengyangchao commentedon Oct 28, 2019
issue also can reproduce on CML laptop HDA
Firmware: 78b022b https://github.com/thesofproject/sof/commits/master
Kernel: 34562a4 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-hda-generic-2ch.tplg same as firmware
Dmesg
logger-error
dmesg.log
logger.log
logger-error.log
Liviali155 commentedon Oct 28, 2019
issue also can reproduce on GLK Chrome I2S
Firmware: 78b022b https://github.com/thesofproject/sof/commits/master
Kernel: 34562a4 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-hda-generic-2ch.tplg same as firmware
Liviali155 commentedon Oct 29, 2019
I have retested it，this issue is a regression caused by commit 74fd0c9，@plbossart please help to check it
plbossart commentedon Oct 29, 2019
Sorry, I am not going to work on this. There is no information that is relevant to help me progress, and I don't have this hardware
@mengdonglin please assign someone else to root cause the issue
Liviali155 commentedon Oct 30, 2019
when run "sudo rtcwake -m mem -s 10 " on idle/aplaying/arecording it only suspend about 1s then wake up,and dmesg show it actually enter suspend
YvonneYang2 commentedon Oct 30, 2019
Issue can be reproduced on CML SDW Laptop with ALC711+ ALC1308+ ALC715.
Scenario 1: aplay0,0 --> pause --> s3 --> wake up then resume --> ipc error for 0x60040000 size 12
scenario 1 logs:
dmesg_pause.log
logger_pause.log
Scenario 2: aplay0,0 --> s3 via "sudo rtcwake -m mem -s 10" --> screen gets dark then light up immediately(shorter than 1s). When screen gets dark, music will stop and music will resume when screen light up.
Scenario 2 dmesg
scenario 2 logs:
dmesg.log
logger.log
Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 9f1bd5b + PR1359
FW: https://github.com/thesofproject/sof/commits/master commit: 2ca6a4a
tplg: https://github.com/bardliao/sof/commits/soundwire-tplg (commit: 0408153), sof-cml-rt711-rt1308-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715
[-][BUG][ICL][HDA]Pause aplay/arecord then enter s3, after wake up and resume aplay/arecord ,it tips "ipc error for 0x60040000 size 12"[/-][+][BUG][s2idle]Pause aplay/arecord then enter s3, after wake up and resume aplay/arecord ,it tips "ipc error for 0x60040000 size 12"[/+]YvonneYang2 commentedon Oct 30, 2019
Issue only reproduced in suspend s2idle mode, not reproduced in suspend deep mode.
4 remaining items
keyonjie commentedon Nov 1, 2019
Hi all, this is actually as expected, we put audio to D0I3 for all cnl.c platforms on S2Idle in today's code, so that actually exposes new issues that our d0i3_incompatible streams can't survive in the D0I3 suspend/resume cycle.
My PR #1418 will help for this if you don't open WoV pipeline, but if you open both normal PCMs and WoV before S2Idle suspend, we will still hit these issues.
So the issue here is actually this: the streams is not resumed correctly in D0I3 suspend/resume cycle.
dengyangchao commentedon Nov 4, 2019
After applied #1418 and tried on ICL RVP HDA, original issue can't reproduce
sinahuang commentedon Nov 11, 2019
Issue still can be reproduced on TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.
dmesg logger
Kernel:https://github.com/thesofproject/linux/commits/integration/soundwire-latest commit: 391b5f9
FW: https://github.com/thesofproject/sof/commits/master commit: fb068e6
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.
dmesg1387.log
logger1387.log
mengdonglin commentedon Nov 11, 2019
@sinahuang we need to wait for #1418 being merged by sof-dev and integration/soundwire-latest, and then double check SDW use cases.
plbossart commentedon Nov 11, 2019
@sinahuang @mengdonglin integration/soundwire-latest now has all the known fixes for suspend/resume please retry (along with the latest firmware)
sinahuang commentedon Nov 12, 2019
Test this issue with legacy interrupt mode and MSI mode, original issue can't be reproduced on both mode.
But there are some other errors shows "error: cl_dsp_init: timeout for HIPCIE done" in dmesg when verified this issue with legacy mode and MSI mode.
Scenario 1: aplay0,0 --> pause --> s3 --> wake up then resume -->dmegs shows "error: cl_dsp_init: timeout for HIPCIE done"
Scenario 2: aplay0,0 --> s3 --> wake up then resume -->dmegs shows "error: cl_dsp_init: timeout for HIPCIE done"
Test recipe
Kernel:https://github.com/thesofproject/linux/commits/integration/soundwire-latest commit: 2933f73
FW: https://github.com/thesofproject/sof/commits/master commit: d1dcdfe
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.
demsg.log
sof_error_trace.log
sof_trace.log
dengyangchao commentedon Nov 13, 2019
Close issue since can't reproduce. Other issue track on #1472
ipmr: Always call ip{,6}_mr_forward() from RCU read-side critical sec…
thunderbolt: Fix KASAN reported stack out-of-bounds read in tb_retime…