[BUG] cl_dsp_init: timeout for HIPCIE done

[aiChaoSONG]

Bug Description
run sudo rtcwake -s 5 -m mem, after the machine sleep back, check dmesg, you can see cl_dsp_init: timeout for HIPCIE done error

To Reproduce

1. reboot
2. run sudo rtcwake -s 5 -m mem

Reproduction Rate
5/5

Impact
no functional impact, just error messages

Platform & Environment
Kernel: topic/sof-dev: f55db62e
SOF: master: 835d876b
Tplg: sof-cml-rt1011-rt5682
Platform: ASUS CML Chromebook with RT5682 codec

[  112.521166] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  112.521173] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  112.521174] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  112.521176] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[  113.021457] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x0 timedout
[  113.021461] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout for HIPCIE done
[  113.021468] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  113.021472] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
[  113.021476] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  113.021482] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  113.021487] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[  113.021491] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[  113.021495] sof-audio-pci 0000:00:1f.3: error: Error code=0xffffffff: FW status=0xffffffff
[  113.021498] sof-audio-pci 0000:00:1f.3: error: iteration 0 of Core En/ROM load failed: -110
[  113.021502] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  113.021511] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[  113.021514] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  113.021519] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1

sof_trace.log
dmesg.log

[ranj063]

@aiChaoSONG Can you please check if this problem is solved by reverting 0e1a961

[aiChaoSONG]

@ranj063 reverting 0e1a961 helps with this issue. @keyonjie we may need to rethink, and deal with code_loading beautifully.

[dengyangchao]

Issue also can reproduce on CML Chrome with onboard codec RT5682 in I2S mode when run Soix_test.sh.

Firmware: 835d876 https://github.com/thesofproject/sof/commits/master
Kernel: f55db62 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-cml-rt5682-max98357a.tplg same as firmware

[  150.682581] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
[  150.714112] sd 1:0:0:0: [sda] Synchronizing SCSI cache
[  150.714792] sd 1:0:0:0: [sda] Stopping disk
[  151.011104] ACPI: EC: interrupt blocked
[  154.750672] ACPI: EC: interrupt unblocked
[  154.778797] sd 1:0:0:0: [sda] Starting disk
[  155.012978] sof-audio-pci 0000:00:1f.3: loading firmware
[  155.012992] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000002 at  00000048
[  155.012999] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at  00000048
[  155.013008] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[  155.013014] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000004 at  00000044
[  155.013017] sof-audio-pci 0000:00:1f.3: booting DSP firmware
[  155.013116] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[  155.013141] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[  155.013150] sof-audio-pci 0000:00:1f.3: period_bytes:0x0
[  155.013153] sof-audio-pci 0000:00:1f.3: periods:1
[  155.013292] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  155.013304] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  155.013310] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  155.013317] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[  155.083963] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[  155.086036] ata2.00: configured for UDMA/133
[  155.513496] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x0 timedout
[  155.513501] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout for HIPCIE done
[  155.513511] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  155.513518] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
[  155.513523] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  155.513534] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  155.513542] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[  155.513548] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[  155.513555] sof-audio-pci 0000:00:1f.3: error: Error code=0xffffffff: FW status=0xffffffff
[  155.513558] sof-audio-pci 0000:00:1f.3: error: iteration 0 of Core En/ROM load failed: -110
[  155.513565] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  155.513578] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[  155.513584] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  155.513591] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1

test_0_fail.log

[dengyangchao]

Also can reproduce on
ICL RVP with onboard codec ALC700 in HDA mode(s2idle)
GLK Chrome with onboard codec DA7219 in I2S mode(s2idle)

And checked on CFL-S RVP ALC700 in HDA mode(deep), issue can't reproduce
so issue only can reproduce on s2idle mode, and related with #1387

[YvonneYang2]

Issue can be reproduced on CML SDW Laptop with ALC711+ ALC1308+ ALC715 mode.

kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: fb40b85 + #1451
FW: https://github.com/thesofproject/sof/commits/master commit: 835d876
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

[keyonjie]

Thanks for reporting this, if we go through the dmesg log, we can find the 1st try in cl_dsp_init() failed and the subsequent try succeed, this is interesting @ranj063