[BUG][CML]"0000:00:1f.3: error: firmware boot failure" occurred during suspend/resume with audio stress test.

[YvonneYang2]

Describe the bug
During suspend/resume with audio stress test, dmesg will show

kernel: [10830.365253] sof-audio-pci 0000:00:1f.3: error: firmware boot failure
kernel: [10830.365272] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
kernel: [10830.365289] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00004000

To Reproduce
1.Boot up system.
2. Run "./check-kmod-load-unload-after-playback.sh -l 10".
(https://github.com/thesofproject/sof-test/blob/master/test-case/check-kmod-load-unload-after-playback.sh)
3. Run "./check-suspend-resume-with-audio.sh -m capture -l 100"
(https://github.com/thesofproject/sof-test/blob/master/test-case/check-suspend-resume-with-audio.sh)

kernel: [10823.694604] ACPI: EC: interrupt blocked
kernel: [10827.880167] sched: RT throttling activated
kernel: [10827.884509] ACPI: EC: interrupt unblocked
kernel: [10828.252236] r8152 2-2.4:1.0 enx00e04c733c81: carrier on
kernel: [10830.365253] sof-audio-pci 0000:00:1f.3: error: firmware boot failure
kernel: [10830.365272] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
kernel: [10830.365289] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00004000
kernel: [10830.365302] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
kernel: [10830.365308] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware after resume -5
kernel: [10830.365326] PM: dpm_run_callback(): pci_pm_resume+0x0/0x80 returns -5
kernel: [10830.365342] PM: Device 0000:00:1f.3 failed to resume: error -5
kernel: [10830.366848] OOM killer enabled.
kernel: [10830.366851] Restarting tasks ... done.
kernel: [10830.376603] PM: suspend exit
kernel: [10831.133262] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60010000 size 108
kernel: [10831.133278] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
kernel: [10831.133293] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
kernel: [10831.133311] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00004000
kernel: [10831.133320] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
kernel: [10831.133336] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0x40000000 rirb 00
kernel: [10831.133343] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
kernel: [10831.133356] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0xf0000000 mask 0x00000003
kernel: [10831.133365] sof-audio-pci 0000:00:1f.3: error: hw params ipc failed for stream 1
kernel: [10831.133372] sof-audio-pci 0000:00:1f.3: error: set pcm hw_params after resume
kernel: [10831.133380] sof-audio-pci 0000:00:1f.3: ASoC: platform prepare error: -110
kernel: [10831.133390]  Speakers: ASoC: prepare FE Speakers failed

Reproduce rate
2/3

Expected result
There's no error info during suspend/resume with audio stress test

Actual result
"0000:00:1f.3: error: firmware boot failure" occurred during suspend/resume with audio stress test.

Test recipe

Kernel:https://github.com/thesofproject/linux/commits/topic/sof-dev commit:c05a3f86 commit: 3914cd2
FW: https://github.com/thesofproject/sof/commits/master commit: d9e3d4d
Tplg: sof-cml-rt1011-rt5682.tplg
Platform: CML Chrome with I2S RT5682

a_dmesg.txt

[YvonneYang2]

The bisect result shows commit e081ba8 cause the issue. Could you please have a look? Thanks ~ @singalsu

[jajanusz]

Can you post full sw+fw logs?

[singalsu]

@YvonneYang2 I have a Comet Lake-U based device so I will try to repeat this.

[YvonneYang2]

Sorry for the wrong bisect result since the issue is not 100% reproducible.
I tried it again then I could reproduce the issue with commit 4fe398e and cannot reproduce with the commit ab42146. So the cause commit may be between the two commit.

Here here are the logs.
sof-trace1.log
dmesg1.log

[singalsu]

@YvonneYang2 Thanks for update. I tried to start with this but I get this error. I have SOF firmware repo fetched to parallel directory and topologies and test topologies were built. What is missing?

root@helios-och-2465:/home/singalsu/git/sof-test/test-case# ./check-kmod-load-unload-after-playback.sh -l 10
2020-05-27 15:45:08 UTC [ERROR] No available topology for pipeline export
2020-05-27 15:45:08 UTC [INFO] Test Result: FAIL!

Since it's apparently not FIR related maybe someone else can look this?

[YvonneYang2]

@YvonneYang2 Thanks for update. I tried to start with this but I get this error. I have SOF firmware repo fetched to parallel directory and topologies and test topologies were built. What is missing?

root@helios-och-2465:/home/singalsu/git/sof-test/test-case# ./check-kmod-load-unload-after-playback.sh -l 10
2020-05-27 15:45:08 UTC [ERROR] No available topology for pipeline export
2020-05-27 15:45:08 UTC [INFO] Test Result: FAIL!

Since it's apparently not FIR related maybe someone else can look this?

Sorry for the not detailed steps.

1.Boot up system.
2.Run command "export TPLG=/lib/firmware/intel/sof-tplg/sof-cml-rt1011-rt5682.tplg
3. Run "./check-kmod-load-unload-after-playback.sh -l 10".
(https://github.com/thesofproject/sof-test/blob/master/test-case/check-kmod-load-unload-after-playback.sh)
4. Run "./check-suspend-resume-with-audio.sh -m capture -l 100"
(https://github.com/thesofproject/sof-test/blob/master/test-case/check-suspend-resume-with-audio.sh)

[singalsu]

@YvonneYang2 I was not able to repeat this. The second script check-suspend-resume-with-audio.sh just froze in round 83. There's no error in dmesg (journctl -f -k) window that I had open.

(I realize now the huge effort in bisect, only single run took very long time)

Edit: I'd like to add that my CML device is maybe not stable with the cheap USB-C power supply that I have. It's a notebook but without the battery so power supply quality is critical. So this freeze could be a power supply issue.

[singalsu]

Sorry for the wrong bisect result since the issue is not 100% reproducible.
I tried it again then I could reproduce the issue with commit 4fe398e and cannot reproduce with the commit ab42146. So the cause commit may be between the two commit.

Here here are the logs.
sof-trace1.log
dmesg1.log

@slawblauciak Can someone else take this? I have in my list the volume and ASRC fixes where I know what to do. This new bisect round no more points to FIR topology.

[slawblauciak]

@singalsu very well, thanks
@YvonneYang2 the new bisect can't be correct, the change you mentioned does not affect CML platforms in any way.