TGL: Chrome: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read

[sathya-nujella]

DUT: TGL Chrome system
BIOS: Coreboot
Kernel: Google Chrome 5.4 kernel

Notes on error:
1)
Multiple reports of this error reported (at least saw 3~4 logs) showing this error
2)
Do not know how to repro, it is reported in random tests.
3)
Some times issue occurred at boot time, some times during suspend/resume

Error snippet-1:

[ 5.809326] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
[ 5.809334] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
[ 5.809346] sof-audio-pci 0000:00:1f.3: error: extended rom status: 0x6000021 0x0 0x0 0x0 0x0 0x0 0x25101c2 0x0
[ 5.809357] sof-audio-pci 0000:00:1f.3: error: dsp init failed after 3 attempts with err: -110
[ 5.809361] sof-audio-pci 0000:00:1f.3: ROM error=0xffffffff: FW status=0xffffffff
[ 5.809384] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[ 5.809386] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware -110
[ 5.859830] sof-audio-pci 0000:00:1f.3: error: hda_dsp_core_reset_enter: timeout on HDA_DSP_REG_ADSPCS read
[ 5.859834] sof-audio-pci 0000:00:1f.3: error: dsp core reset failed: core_mask 1
[ 5.859946] sof-audio-pci 0000:00:1f.3: error: sof_probe_work failed err: -110

Error snippet-2:

2021-03-18T14:23:26.983675Z ERR kernel: [ 5159.472527] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
2021-03-18T14:23:26.983677Z ERR kernel: [ 5159.472539] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
2021-03-18T14:23:26.983681Z ERR kernel: [ 5159.472558] sof-audio-pci 0000:00:1f.3: error: extended rom status: 0x6000021 0x0 0x0 0x0 0x0 0x0 0x25101c2 0x0
2021-03-18T14:23:26.983683Z ERR kernel: [ 5159.472587] sof-audio-pci 0000:00:1f.3: error: dsp init failed after 3 attempts with err: -110
2021-03-18T14:23:26.983685Z ERR kernel: [ 5159.472598] sof-audio-pci 0000:00:1f.3: ROM error=0xffffffff: FW status=0xffffffff
2021-03-18T14:23:26.983686Z ERR kernel: [ 5159.472663] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
2021-03-18T14:23:26.983687Z ERR kernel: [ 5159.472665] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware after resume -110
2021-03-18T14:23:26.983688Z ERR kernel: [ 5159.472672] PM: dpm_run_callback(): pci_pm_resume+0x0/0xc0 returns -110
2021-03-18T14:23:26.983692Z INFO kernel: [ 5159.472676] sof-audio-pci 0000:00:1f.3: pci_pm_resume+0x0/0xc0 returned -110 after 894734 usecs
2021-03-18T14:23:26.983693Z ERR kernel: [ 5159.472683] PM: Device 0000:00:1f.3 failed to resume: error -110

[plbossart]

@sathya-nujella do you have a servo board or UART connection?

@ranj063 and I have seen similar issues while doing pm_runtime_resume() before a shutdown/reboot. I have a 100% repro rate on my devices (not Chromebooks) in that sequence, whereas I have never seen such a failure during regular suspend/resume tests. Wondering if you can give it a try and check if the logs before the reboot look ok (need UART for this)

[sathya-nujella]

@sathya-nujella do you have a servo board or UART connection?

Yes, I have servo connected DUT.

[ranj063]

@plbossart the reproduction rate is very low for this issue. We might need to do some reboot stress tests to reproduce it

[keyonjie]

@plbossart @ranj063 This could have relationship with that we are using difference suspend/resume logic, comparing with the cAVS FW/driver.

The state 0x6000021 means hang at WAIT_FOR_CSE_CSR(0x6) with _ROM_CSE_IPC_RESET_PHASE_1(0x21).

[cujomalainey]

I see the IMR tag, what exactly is IMR?

[yongzhi1]

I see the IMR tag, what exactly is IMR?

Isolated Memory Regions?

[ranj063]

@plbossart @ranj063 This could have relationship with that we are using difference suspend/resume logic, comparing with the cAVS FW/driver.

The state 0x6000021 means hang at WAIT_FOR_CSE_CSR(0x6) with _ROM_CSE_IPC_RESET_PHASE_1(0x21).

@keyonjie and what is the difference you're talking about here? Is it in terms of the fw boot sequence or just the fact that runtime PM resume doesnt involve FW authentication?

[keyonjie]

@plbossart @ranj063 This could have relationship with that we are using difference suspend/resume logic, comparing with the cAVS FW/driver.
The state 0x6000021 means hang at WAIT_FOR_CSE_CSR(0x6) with _ROM_CSE_IPC_RESET_PHASE_1(0x21).

@keyonjie and what is the difference you're talking about here? Is it in terms of the fw boot sequence or just the fact that runtime PM resume doesnt involve FW authentication?

I meant just the runtime PM resume case, but @sathya-nujella told me that this happened on the boot case also, so it looks more miracle to me now, not saying that we have never reproduce it at our end.

[plbossart]

well we have to split the variables here.
a) if there is a problem on a cold boot, it's squarely a CSE issue
b) if there is a problem on a D3 exit, it may be because CSE assumes the authentication is done only once. That said I don't see how we could change the flows at this point, TGL FW is past the PV point and having the firmware save/restore its own context in IMR (DDR not visible to the Linux kernel) would be a major change.

[mwasko]

@ranj063 @keyonjie it look like we are reading ROM & FW status too late - the DSP is probably already power off and that is why we get 0xFFFFF. We should fix that to gather more information about FW load failure reason

[plbossart]

@ranj063 @keyonjie it look like we are reading ROM & FW status too late - the DSP is probably already power off and that is why we get 0xFFFFF. We should fix that to gather more information about FW load failure reason

Not following the comment and not getting what the suggestion is @mwasko. we are not turning the DSP off, it's on boot/resume that the problem happens.