[DUT][ICL] random error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read

[xiulipan]

random dsp error message will appear on ICL RVP when FW need to be loaded(boot/runtime_pm_resume/s3_resume)

dmesg example

kernel: [  409.510390] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
kernel: [  409.510423] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
kernel: [  409.510428] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
kernel: [  409.510435] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
kernel: [  409.510981] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
kernel: [  409.510987] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
kernel: [  409.511140] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
kernel: [  409.811376] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000010 timedout
kernel: [  409.811379] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
kernel: [  409.811403] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000010
kernel: [  409.811426] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
kernel: [  409.811447] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000010
kernel: [  409.811456] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
kernel: [  409.811464] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
kernel: [  409.811469] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
kernel: [  409.811472] sof-audio-pci 0000:00:1f.3: iteration 0 of Core En/ROM load failed: -110
kernel: [  409.811493] sof-audio-pci 0000:00:1f.3: Error code=0xffffffff: FW status=0xffffffff
kernel: [  409.812051] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
kernel: [  409.812083] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
kernel: [  409.812088] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
kernel: [  409.812095] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
kernel: [  409.812887] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
kernel: [  409.812909] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
kernel: [  409.813063] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
kernel: [  409.887374] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 successful
kernel: [  409.897918] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5 successful
kernel: [  409.898383] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x140000 successful
kernel: [  409.898395] sof-audio-pci 0000:00:1f.3: Firmware download successful, booting...
kernel: [  409.905888] sof-audio-pci 0000:00:1f.3: ipc rx: 0x70000000: FW_READY
kernel: [  409.905893] sof-audio-pci 0000:00:1f.3: ipc: DSP is ready 0x70000000 offset 0x81000
kernel: [  409.905901] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x70000000: FW_READY
kernel: [  409.905990] sof-audio-pci 0000:00:1f.3: firmware boot complete

previous discussion in thesofproject/sof-test#16
@bardliao @ranj063

[stripes416]

Update: I've been watching for this during manual testing on ICL for the last several days and I haven't seen it.

[Liviali155]

On 20200401 daily test reproduced this issue again when do module load/unload test,sof/dev(3bdd89d)+master(1e39cee),I reproduced it manually,but can not reproduce it

Removing snd_soc_core
Removing snd_hda_codec
Removing snd_hda_core
Removing snd_hwdep
Removing snd_compress
Removing snd_pcm
2020-03-31 23:46:11 UTC [REMOTE_INFO] checking for general errors after kmod unload with sof-kernel-log-check tool
2020-03-31 23:46:11 UTC [ERROR] Caught dmesg error
===========================>>
Mar 31 16:46:08 jf-icl-rvp-hda-1 kernel: [ 6623.273917] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
<<===========================
2020-03-31 23:46:11 UTC [REMOTE_ERROR] error found after kmod unload is real error, failing
2020-03-31 23:46:11 UTC [REMOTE_INFO] Test Result: FAIL!

check-kmod-load-unload-50.sh.txt
cmd.txt
dmesg.txt

[Liviali155]

On icl reproduced this issue with latest sof/dev(052e45d) +master(b4e8b1e)

f-icl-rvp-hda-4

Reproduction Rate
2/2

To Reproduce
1.sudo reboot
2.cd sof-test
3.cd test-case
4.export TPLG=/lib/firmware/intel/sof-tplg/sof-hda-generic-4ch.tplg
5../check-kmod-load-unload-after-playback.sh -l 50

dmesg_error.log

jf-icl-rvp-hda-4 kernel: [  805.732942] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
jf-icl-rvp-hda-4 kernel: [  805.732948] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
jf-icl-rvp-hda-4 kernel: [  805.732955] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
jf-icl-rvp-hda-4 kernel: [  805.733754] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
jf-icl-rvp-hda-4 kernel: [  805.733763] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
jf-icl-rvp-hda-4 kernel: [  806.033805] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000010 timedout
jf-icl-rvp-hda-4 kernel: [  806.033808] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
jf-icl-rvp-hda-4 kernel: [  806.033835] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000010
jf-icl-rvp-hda-4 kernel: [  806.033857] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
jf-icl-rvp-hda-4 kernel: [  806.033878] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000010
jf-icl-rvp-hda-4 kernel: [  806.033887] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
jf-icl-rvp-hda-4 kernel: [  806.033895] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
jf-icl-rvp-hda-4 kernel: [  806.033901] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
jf-icl-rvp-hda-4 kernel: [  806.033903] sof-audio-pci 0000:00:1f.3: iteration 0 of Core En/ROM load failed: -110
jf-icl-rvp-hda-4 kernel: [  806.033924] sof-audio-pci 0000:00:1f.3: Error code=0xffffffff: FW status=0xffffffff
jf-icl-rvp-hda-4 kernel: [  806.034212] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
jf-icl-rvp-hda-4 kernel: [  806.034230] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
jf-icl-rvp-hda-4 kernel: [  806.034236] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
jf-icl-rvp-hda-4 kernel: [  806.034243] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
jf-icl-rvp-hda-4 kernel: [  806.034776] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
jf-icl-rvp-hda-4 kernel: [  806.034800] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
jf-icl-rvp-hda-4 kernel: [  806.109817] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 successful
jf-icl-rvp-hda-4 kernel: [  806.120735] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5 successful
jf-icl-rvp-hda-4 kernel: [  806.121255] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x140000 successful
jf-icl-rvp-hda-4 kernel: [  806.121260] sof-audio-pci 0000:00:1f.3: Firmware download successful, booting...

dmesg.txt
slogger.txt

[mengdonglin]

Transfer to SOF repo from linux issue No. 1703, to group with other DSP boot failure.

[Liviali155]

On icl run multiple-pipeline-playback also can reproduce this issue with latest sof/dev(8f1c6ad) +master(de2dcbb)

After error occured ,all the pipeline can work

1.sudo reboot
2.cd sof-test
3.cd test-case
4.export TPLG=/lib/firmware/intel/sof-tplg/sof-hda-generic-4ch.tplg
5../multiple-pipeline-playback.sh -l 50

Reproduction rate
Run 50times,failed at 44th

dmesg_error.log

   [  777.984804] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
[  777.984834] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000      

dmesg0428.log

sof-logger0428.log,

[tlauda]

0x6000010 indicates that ROM is still waiting for response from CSE regarding IMR allocation. What is the value of the timeout? It looks like timing issue.

[Liviali155]

On icl run multiple-pipeline-playback also can reproduce this issue with latest sof/dev(8f1c6ad) +master(de2dcbb)

After error occured ,all the pipeline can work

1.sudo reboot
2.cd sof-test
3.cd test-case
4.export TPLG=/lib/firmware/intel/sof-tplg/sof-hda-generic-4ch.tplg
5../multiple-pipeline-playback.sh -l 50

Reproduction rate
Run 50times,failed at 44th

dmesg_error.log
dmesg0428.log

sof-logger0428.log,

Add the log complete
dmesg042.log
sof-logger0429.log