Repository navigation
[CML] suspend fails at the second time #1011
Description
Activity
- addedbugSomething isn't working as expectedSomething isn't working as expectedCMLApplies to Comet Lake platformApplies to Comet Lake platform
on Feb 15, 2019 @xun2z please help to reproduce this issue.
- addedP1Blocker bugs or important featuresBlocker bugs or important features
on Feb 18, 2019 Hi,
I try to reproduce issue on WHL RVP + I2S, but I have issue with entering suspend: #1019In spite of that FW and tplg loaded properly, aplay works.
kernel: topic/sof-dev: branch 69a41dab
FW: 2a86314
topology: sof-cnl-nocodec.tplgOn this kernel on dmesg there is no msg from CTX_SAVE/CTX_RESTORE. Is it excpected?
On this kernel on dmesg there is no msg from CTX_SAVE/CTX_RESTORE. Is it excpected?
You will see something like "ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE" if CONFIG_SND_SOC_SOF_DEBUG_VERBOSE_IPC is set in kernel config.
You can set it from make menuconfigDevice Drivers ---> <*> Sound card support ---><*> Advanced Linux Sound Architecture ---><M> ALSA for SoC audio support --->[*] SOF verbose IPC logs[ 34.067417] sof-audio sof-audio: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.067933] sof-audio sof-audio: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.067981] sof-audio sof-audio: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.068464] sof-audio sof-audio: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.068509] sof-audio sof-audio: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.068968] sof-audio sof-audio: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.069015] sof-audio sof-audio: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.069516] sof-audio sof-audio: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE [ 34.069542] sof-audio sof-audio: ipc tx: 0x40020000: GLB_PM_MSG: CTX_RESTORE [ 34.069709] sof-audio sof-audio: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTORE [ 34.069806] serial 00:06: activated [ 34.218978] ata3: SATA link down (SStatus 4 SControl 300) [ 34.300774] atkbd serio0: Failed to deactivate keyboard on isa0060/serio0 [ 34.349107] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0 [ 34.349110] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 7:0 [ 34.349547] acpi LNXPOWER:08: Turning OFF [ 34.350155] acpi LNXPOWER:07: Turning OFF [ 34.351819] OOM killer enabled. [ 34.351820] Restarting tasks ... done. [ 34.478003] video LNXVIDEO:00: Restoring backlight state [ 34.478013] PM: suspend exit [ 34.566699] sof-audio sof-audio: ipc rx: 0x90020000: GLB_TRACE_MSG [ 34.566802] sof-audio sof-audio: ipc rx done: 0x90020000: GLB_TRACE_MSG [ 34.684789] atkbd serio0: Failed to enable keyboard on isa0060/serio0 [ 35.066587] sof-audio sof-audio: ipc rx: 0x90020000: GLB_TRACE_MSG [ 35.066668] sof-audio sof-audio: ipc rx done: 0x90020000: GLB_TRACE_MSG [ 35.124794] sof-audio sof-audio: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE [ 35.428804] sof-audio sof-audio: error: ipc timed out for 0x40010000 size 0x4c [ 35.428818] sof-audio sof-audio: status: fw entered - code 00000005 [ 35.429594] sof-audio sof-audio: error: unexpected fault 0x00000000 trace 0x00004000 [ 35.429603] sof-audio sof-audio: error: ctx_save ipc error during suspend -110 [ 35.429632] sof-audio sof-audio: FW Poll Status: reg=0x1010f0f successful [ 35.430658] sof-audio sof-audio: FW Poll Status: reg=0xf0f successful [ 35.430663] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask f [ 35.430714] sof-audio sof-audio: Debug PCIR: 00000000 at 00000044 [ 35.430721] sof-audio sof-audio: Debug PCIW: 00000010 at 00000044 [ 36.007936] e1000e: enp0s31f6 NIC Link is Up 100 Mbps Full Duplex, Flow Control: None [ 36.007945] e1000e 0000:00:1f.6 enp0s31f6: 10/100 speed: disabling TSO
Test env:
sof cml-001-drop-stable: 1f5a965
kernel topic/cros-sof-v4.19: f69d61898a
tplg: sof-cml-rt5682.tplgTest env:
sof cml-002-drop-stable: 2a86314
kernel topic/cros-sof-v4.19: 8492020d5967
tplg: sof-cml-rt5682.tplgTest env:
sof: master dcd825b
kernel topic/sof-dev 69a41da
tplg: sof-cml-rt5682.tplgThough ctx_save error occurs, whl will not be blocked.
On this kernel on dmesg there is no msg from CTX_SAVE/CTX_RESTORE. Is it excpected?
You will see something like "ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE" if CONFIG_SND_SOC_SOF_DEBUG_VERBOSE_IPC is set in kernel config.
You can set it from make menuconfigDevice Drivers ---> <*> Sound card support ---><*> Advanced Linux Sound Architecture ---><M> ALSA for SoC audio support --->[*] SOF verbose IPC logsI have this option enabled.
Due to reboot issue #662 on WHL RVP+I2S instead of suspend I use another WHL to find a repro.
On WHL RVP + HDA reworks I can playback on HDA (codec ALC700) and enter suspend/resume in loop. It works fine on each iteration.
kernel: cros-sof-v4.19 / 8492020d5967
FW: cml-002-drop-stable / dcd825b
tplg for hda: sof-hda-generic.tplgBut I see in dmesg error with ctx:
[ 5894.581642] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 5894.582030] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x40010000 size 0xc
[ 5894.582044] sof-audio-pci 0000:00:1f.3: error: ctx_save ipc error during suspend -1@bardliao could you check what happend in this function:
error: ipc error for 0x40010000 size 0xclog from last iteration: playback/suspend/resume
dmesg3.txt@bardliao could you check what happend in this function:
error: ipc error for 0x40010000 size 0xc@emilchudzik Please see #984 And it can be fixed by thesofproject/linux#651
I have made check with patch thesofproject/linux#651. And playback and suspend works fine in loop. There is no error message with it.
Platform: WHL_RVP
kernel: cros-sof-v4.19 / 8492020d5967
FW: cml-002-drop-stable / dcd825b
tplg for hda: sof-hda-generic.tplg[ 179.540605] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE [ 179.540897] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE [ 179.540928] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful [ 179.541952] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful [ 179.541958] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f [ 179.541997] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000044 -- [ 187.684856] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE [ 187.684864] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.1.HDA0.OUT id 3 [ 187.684879] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE [ 187.685016] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE [ 187.685056] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40020000: GLB_PM_MSG: CTX_RESTORE [ 187.685206] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTOREI also try to check as Bard ask - on the same platform using nocodec mode.
I prepare suitable kernel and topology. Then trying to go suspend cause OS freezing all the time.
G3 on platform restore booting system again.4 remaining items
@plbossart @emilchudzik @bardliao this simple change in the kernel fixes the issue for me but it was simply a trial and error on my part. The value of 70ms timeout was based on the skylake driver and it worked in GLK.
I could use some feedback on how to determine the correct value to be set.diff --git a/sound/soc/sof/intel/hda.h b/sound/soc/sof/intel/hda.h
index 54b817358e31..ee4817abc251 100644
--- a/sound/soc/sof/intel/hda.h
+++ b/sound/soc/sof/intel/hda.h
@@ -198,7 +198,7 @@
#define HDA_DSP_RESET_TIMEOUT 50
#define HDA_DSP_BASEFW_TIMEOUT 3000
#define HDA_DSP_INIT_TIMEOUT 500
-#define HDA_ROM_INIT_TIMEOUT 70
+#define HDA_ROM_INIT_TIMEOUT 100
#define HDA_DSP_CTRL_RESET_TIMEOUT 100
#define HDA_DSP_WAIT_TIMEOUT 500 /* 500 msec /
#define HDA_DSP_REG_POLL_INTERVAL_US 500 / 0.5 msec */I suggest at least 300 ms for HDA_ROM_INIT_TIMEOUT.
I have just checked flow from this issue topic.
Platform: Hatch
kernel: cros-sof-v4.19 / 8492020d5967 + thesofproject/linux#651.
FW: cml-002-drop-stable / dcd825b
tplg: cml-002-drop-stable / dcd825b sof-cml-rt5682.zipCommands "suspend_stress_test" in my opion return fail to suspend (see below screenshot).
When I use more than 2 iter (I mean paramneter: -c2) -> unable to enter suspend.
When I use -c1 several times -> platform trying to go suspend: screen is off, but ssh is still active. So it seems like script "suspend_stress_test" didn't enter platform to suspend even in first iterartion.Is there any options to go suspend in "user natural way"? e.g. pressing button on platform to double check if it is platform or script issue?
Short pressing "pwr" button try to power off.localhost ~ # suspend_stress_test -c 1 Running 1 iterations with: suspend: 5-10 seconds wake: 5-10 seconds backup_rtc: false errors_fatal: true fw_errors_fatal: true bugs fatal: true warnings fatal: false crcs fatal: true suspend command: powerd_dbus_suspend --delay=0 wakeup source to ignore: none record_dmesg_dir: pm_print_times: true powerd start/running, process 3340 tlsdated stop/waiting Suspend 1 of 1: sleep for 7 seconds...Suspend failed, s0ix count did not increment from 0) powerd start/running, process 3647 tlsdated start/running, process 3674 Finished 1 iterations. Suspend failures: 0 Wakealarm errors: 0 Firmware log errors: 0 s0ix errors: 1I didn't see that thinks or WHL RVP.
Here I use: rtcwake command or short pressing power button.
Both method properly entering suspend WHL RVP.I suggest at least 300 ms for HDA_ROM_INIT_TIMEOUT.
@lbetlej we used to have this value set to 300ms before. But the suspend stress test failed and after following the analysis done fro skylake, it was decided to use 70ms. I might leave it at 70 for GLK and only change it to 300ms for CML.
thesofproject/linux#704 fixes this issue.
@emilchudzik could you please check if you can run a stress test with this change in the kernelsuspend_stress_test -c 500
@emilchudzik did thesofproject/linux#704 fix it for you ? If so we should close.
on Hatch this patch doesn't help. I have still issue with first suspend, suspending doesn't work -> screen is off for a while, but logs return:
Suspend 1 of 1: sleep for 7 seconds...Suspend failed, s0ix count did not increment from 0)I suggest to check repro on CML (@bardliao as submitter) and if doesn't exists then closed it.
I can rise new issue that on Hatch (CML CHromebook) suspending doesn't work at whole using scripts:
suspend_stress_test@emilchudzik I'm going to send you the latest coreboot that is needed for suspend stress test to work. Please give it a try
@emilchudzik I'm going to send you the latest coreboot that is needed for suspend stress test to work. Please give it a try
@ranj063 can you send me too, I have met the same problem as @emilchudzik too.
THXon Hatch this patch doesn't help. I have still issue with first suspend, suspending doesn't work -> screen is off for a while, but logs return:
Suspend 1 of 1: sleep for 7 seconds...Suspend failed, s0ix count did not increment from 0)@emilchudzik Is this issue solved? I've met the same problem, and I've turned on HIPM,DIPM,DEVSLP, still can't solved the problem. Please kindly teach me how to do.
THX
suspend_stress_test will fail at 2nd iteration.
kernel: topic/cros-sof-v4.19 branch 8492020
fw: master 8483480
topology: sof-cml-rt5682 (with PR #976)
Platform: CML Chromebook
In fact, there are some error at the 1st resume:
And similar error at the 2nd suspend, finally leads to suspend fail.
The issue won't be solved by thesofproject/linux#651 which will prevent reading reply of CTX_SAVE
dmesg_1.txt
dmesg_2.txt