Repository navigation
[BUG][CML] PM: Some devices failed to suspend, or early wake event detected #984
Description
Describe the bug
PM: Some devices failed to suspend, or early wake event detected during S3 with playback stress test.
To Reproduce
Run S3 with playback stress test "aplay -Dhw:0,0 -r48000 -c2 -fs16_le /dev/zero & sudo ./stress-s3.sh 500 1 1"
Expected behavior
Aplay stopped at 23th and Some devices failed to suspend, or early wake event detected is shown then ipc error can be found in dmesg
Frequency:1/25
Impact
aplay should be continued and enter s3 normally.
Environment
Kernel: 9453da1 https://github.com/lyakh/linux/tree/ipc-timeout (with PR895)
FW:b527fd7 https://github.com/lyakh/sof/tree/ipc-timeout (with PR1354)
Topology:Same as above FW repo, file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplg
kconfig:https://drive.google.com/open?id=1U4pR28-g_OlCZFFpXzWpy2uMKnvV8i-C
unset CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE
error logger:
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 COMP 20790619313.697918 nan rc/audio/component.c:140 comp_set_state() error: wrong state = 1, COMP_TRIGGER_START
0 1 IPC 20790619320.156250 6.458333 src/audio/pipeline.c:606 pipeline_trigger() error: ret = -22, host->comp.id = 1, cmd = 1
0 1 IPC 20790619326.875000 6.718750 src/ipc/handler.c:513 ipc: comp 1 trigger 0x40000 failed -22
0 1 COMP 20790619549.270836 222.395828 rc/audio/component.c:161 comp_set_state() error: wrong state = 1, COMP_TRIGGER_STOP
0 1 IPC 20790619555.312500 6.041667 src/audio/pipeline.c:606 pipeline_trigger() error: ret = -22, host->comp.id = 1, cmd = 0
0 1 IPC 20790619561.979168 6.666667 src/ipc/handler.c:513 ipc: comp 1 trigger 0x50000 failed -22
0 1 DMA 20791375954.010418 756392.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
dmesg
[ 466.828495] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 5
[ 466.828501] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 466.828649] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 466.828653] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 466.828842] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 466.828846] sof-audio-pci 0000:00:1f.3: In hda_link_pcm_trigger cmd=5
[ 466.828849] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 466.829003] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 467.444918] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 467.444953] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 467.845591] PM: Some devices failed to suspend, or early wake event detected
[ 467.845713] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 5:0
[ 467.845773] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0
[ 467.845788] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 7:0
[ 468.050234] iwlwifi 0000:00:14.3: BIOS contains WGDS but no WRDS
[ 468.054954] OOM killer enabled.
[ 468.054954] Restarting tasks ... done.
[ 468.070838] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 468.070846] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 468.071004] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x60040000 size 12
[ 468.071007] HDA Analog: ASoC: trigger FE failed -22
[ 468.071009] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 468.071035] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 468.071154] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x60050000 size 12
[ 468.071155] HDA Analog: ASoC: trigger FE failed -22
[ 468.131436] PM: suspend exit
[ 468.676149] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 468.676158] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 468.676441] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 468.676474] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 468.676717] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 468.676842] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
[ 468.944943] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 468.945059] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 469.444901] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 469.445014] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
Attach failed 23th logs and previous 22th logs
test_22.log
test_23.log
s3_test_23_logger_all.log
s3_test_23_logger_error.log
s3_test_22_logger_all.log
Activity
lyakh commentedon May 28, 2019
@ClarexZhou I presume this is run with pulseaudio enabled? I tried this and I've got a different and supposedly uglier failure. The first suspend-resume goes normal, after the resume I see one-two trigger START / STOP in the kernel log. The second resume looks much worse already - START / STOP are running back to back many times per second. Then the third suspend kicks in, and the resume fails with a similar "IPC error":
and again START / STOP attempts run back to back. These triggers are caused by pulseaudio, I disabled it and they disappeared. But why are they happening?
ClarexZhou commentedon May 29, 2019
Error occurred with IPC timed out '0x60040000: GLB_STREAM_MSG: TRIG_START' during s3 with playback test. Failed at 81th.
Headset type query pops up (amixer cget numid=34 to check headphone Mic jack is on)when error occurred, though always without headset connection during testing.
Environment
Kernel: https://github.com/lyakh/linux/tree/ipc-timeout commit d8b5fdd (with PR895 and PR977)
FW:https://github.com/lyakh/sof/tree/ipc-timeout commit 47dc14d (with PR1354 and PR1470)
Kconfig: disable CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE in kernel config.
error logger:
81th dmesg
80th dmesg:
YvonneYang2 commentedon Jun 17, 2019
Issues still reproduced during Suspeand & Resume with playback_Analog_50 times stress test.
But only shows "PM: Some devices failed to suspend, or early wake event detected" message in dmesg log, no ipc error info, and has no impact on audio function.
Environment
Firmware: 6cc8da10 https://github.com/thesofproject/sof/tree/cml-hda-dmic-001-drop-stable
Kernel: f081174 https://github.com/thesofproject/linux/tree/release/sof-v5.0
Topology: file: sof-hda-generic.tplg same path as firmware
platform： CML
No sof-logger error info.
dmesg
test_41_dmesg.log
s3_test_41_logger_all.log
ClarexZhou commentedon Jun 24, 2019
@RanderWang , Rander's analysis as below:
And error not seen on stress test result with minimum of 5s delay after suspending and wait 5s after resuming before suspending again
ranj063 commentedon Jun 24, 2019
@ClarexZhou could you please update the test script upstream and submit the PR?
ClarexZhou commentedon Jun 25, 2019
Scripts will update later. Close this bug and track in #1057 for aplay exit and ipc error issue when enter and wake S3 in 1s.
ClarexZhou commentedon Jun 25, 2019
Scripts are updated and merged in sofcitest