[CFL] error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read

[chmooreck]

HP Zbook 17 G6, Realtek ALC285 + DMIC, i7-9850H

When trying to use sof audio I get:
$ dmesg | grep sof
[ 3.434290] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 3.434291] software IO TLB: mapped [mem 0x912b1000-0x952b1000] (64MB)
[ 5.379159] sof-audio-pci 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100
[ 5.379161] sof-audio-pci 0000:00:1f.3: Digital mics found on Skylake+ platform, using SOF driver
[ 5.379168] sof-audio-pci 0000:00:1f.3: enabling device (0000 -> 0002)
[ 5.379285] sof-audio-pci 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if 0x040100
[ 5.379314] sof-audio-pci 0000:00:1f.3: init of i915 and HDMI codec failed
[ 5.381439] sof-audio-pci 0000:00:1f.3: use msi interrupt mode
[ 5.390891] sof-audio-pci 0000:00:1f.3: hda codecs found, mask 1
[ 5.390892] sof-audio-pci 0000:00:1f.3: using HDA machine driver skl_hda_dsp_generic now
[ 5.390895] sof-audio-pci 0000:00:1f.3: DMICs detected in NHLT tables: 4
[ 6.295941] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
[ 6.295968] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
[ 6.296018] sof-audio-pci 0000:00:1f.3: error: extended rom status: 0x6000021 0x0 0x0 0x0 0x0 0x0 0x183011b 0x0
[ 6.296195] sof-audio-pci 0000:00:1f.3: error: dsp init failed after 3 attempts with err: -110
[ 6.296236] sof-audio-pci 0000:00:1f.3: ROM error=0xffffffff: FW status=0xffffffff
[ 6.296343] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
[ 6.296476] sof-audio-pci 0000:00:1f.3: error: extended rom status: 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff
[ 6.296484] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[ 6.296485] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware -110
[ 6.346978] sof-audio-pci 0000:00:1f.3: error: hda_dsp_core_reset_enter: timeout on HDA_DSP_REG_ADSPCS read
[ 6.346979] sof-audio-pci 0000:00:1f.3: error: dsp core reset failed: core_mask f
[ 6.347191] sof-audio-pci 0000:00:1f.3: error: sof_probe_work failed err: -110

I tried it with 1.5.1 (from gentoo repository) and 1.6 (from sof git) firmware with the same result.

Current firmware:
$ ls -ld /lib/firmware/intel/sof*
drwxr-xr-x 4 root root 4096 09-29 17:35 /lib/firmware/intel/sof
lrwxrwxrwx 1 root root 13 09-29 17:33 /lib/firmware/intel/sof-tplg -> sof-tplg-v1.6
drwxr-xr-x 2 root root 4096 09-25 13:28 /lib/firmware/intel/sof-tplg-v1.5.1
drwxr-xr-x 2 root root 12288 09-29 13:17 /lib/firmware/intel/sof-tplg-v1.6

$ ls -ld /lib/firmware/intel/sof/*
lrwxrwxrwx 1 root root 33 09-29 17:33 /lib/firmware/intel/sof/sof-apl.ri -> v1.6/intel-signed/sof-apl-v1.6.ri
lrwxrwxrwx 1 root root 20 09-29 17:33 /lib/firmware/intel/sof/sof-bdw.ri -> v1.6/sof-bdw-v1.6.ri
lrwxrwxrwx 1 root root 20 09-29 17:34 /lib/firmware/intel/sof/sof-byt.ri -> v1.6/sof-byt-v1.6.ri
lrwxrwxrwx 1 root root 33 09-29 17:34 /lib/firmware/intel/sof/sof-cfl.ri -> v1.6/intel-signed/sof-cnl-v1.6.ri
lrwxrwxrwx 1 root root 20 09-29 17:34 /lib/firmware/intel/sof/sof-cht.ri -> v1.6/sof-cht-v1.6.ri
lrwxrwxrwx 1 root root 33 09-29 17:34 /lib/firmware/intel/sof/sof-cml.ri -> v1.6/intel-signed/sof-cnl-v1.6.ri
lrwxrwxrwx 1 root root 33 09-29 17:34 /lib/firmware/intel/sof/sof-cnl.ri -> v1.6/intel-signed/sof-cnl-v1.6.ri
lrwxrwxrwx 1 root root 33 09-29 17:34 /lib/firmware/intel/sof/sof-glk.ri -> v1.6/intel-signed/sof-apl-v1.6.ri
lrwxrwxrwx 1 root root 33 09-29 17:35 /lib/firmware/intel/sof/sof-icl.ri -> v1.6/intel-signed/sof-icl-v1.6.ri
drwxr-xr-x 4 root root 4096 09-25 13:28 /lib/firmware/intel/sof/v1.5.1
drwxr-xr-x 4 root root 4096 09-29 13:17 /lib/firmware/intel/sof/v1.6

I was redirected here by Pierre Bossart from https://bugzilla.kernel.org/show_bug.cgi?id=201251#c208

[plbossart]

@lgirdwood @jajanusz FYI, looks like there's a firmware authentication issue here?

[chmooreck]

Looks similar to:
thesofproject/sof#2842

[plbossart]

@chmooreck do you mind providing a link to the results of 'alsa-info'? I wonder if this happens on an IceLake device, for which we've had several issues including in our own testing.

[chmooreck]

$ lspci -vs 00:1f.3
00:1f.3 Multimedia audio controller: Intel Corporation Cannon Lake PCH cAVS (rev 10)
Subsystem: Hewlett-Packard Company Cannon Lake PCH cAVS
Flags: bus master, fast devsel, latency 64, IRQ 16
Memory at 404a108000 (64-bit, non-prefetchable) [size=16K]
Memory at 404a000000 (64-bit, non-prefetchable) [size=1M]
Capabilities:
Kernel driver in use: sof-audio-pci
Kernel modules: snd_hda_intel, snd_soc_skl, snd_sof_pci

alsa-info.log

with snd_hda_intel (5.8.11-gentoo):
alsa-info-hda-intel.log

[plbossart]

@chmooreck ok so that's CannonLake. I don't recall seeing issues with this.

Maybe we should try to see if the authentication also fails with the Skylake/SST driver. Can you try with this in /etc/modprobe.d/alsa-base.conf

options snd_intel_dspcfg dsp_driver=2

This may fail at a later point but this is just to see how far the driver would go and if you manage to get past the firmware signature authentication point.

[chmooreck]

$ cat /etc/modprobe.d/alsa.conf 
# Alsa kernel modules' configuration file.

# ALSA portion
alias char-major-116 snd
# OSS/Free portion
alias char-major-14 soundcore

##
## IMPORTANT:
## You need to customise this section for your specific sound card(s)
## and then run `update-modules' command.
## Read alsa-driver's INSTALL file in /usr/share/doc for more info.
##
##  ALSA portion
## alias snd-card-0 snd-interwave
## alias snd-card-1 snd-ens1371
##  OSS/Free portion
## alias sound-slot-0 snd-card-0
## alias sound-slot-1 snd-card-1
##

# OSS/Free portion - card #1
alias sound-service-0-0 snd-mixer-oss
alias sound-service-0-1 snd-seq-oss
alias sound-service-0-3 snd-pcm-oss
alias sound-service-0-8 snd-seq-oss
alias sound-service-0-12 snd-pcm-oss
##  OSS/Free portion - card #2
## alias sound-service-1-0 snd-mixer-oss
## alias sound-service-1-3 snd-pcm-oss
## alias sound-service-1-12 snd-pcm-oss

alias /dev/mixer snd-mixer-oss
alias /dev/dsp snd-pcm-oss
alias /dev/midi snd-seq-oss

# Set this to the correct number of cards.
options snd cards_limit=10

blacklist snd-hda-intel
#blacklist snd-soc-skl
#blacklist snd-sof
#blacklist snd-sof-pci
#blacklist snd-sof-intel-hda
#blacklist snd-sof-intel-hda-common
#blacklist snd-sof-intel-byt
#blacklist snd-sof-intel-ipc
#blacklist snd-sof-xtensa-dsp

options snd-intel-dspcfg dsp_driver=2

alsa-info-sst.log

[plbossart]

@chmooreck sorry, I was interested in the entire dmesg log only, can you please share it?

[chmooreck]

There isn't anything special, maybe i should enable some debug options ?

dmesg-sst.log

P.S. it's 22:50 here so next info will be available in ~8h

[plbossart]

please try with

options snd_soc_skl dyndbg=+p

[chmooreck]

$ dmesg  |grep snd
[    5.495099] snd_soc_skl 0000:00:1f.3: enabling device (0000 -> 0002)
[    5.495360] snd_soc_skl 0000:00:1f.3: chipset global capabilities = 0x9701
[    5.495377] snd_soc_skl 0000:00:1f.3: oem_id INTEL , oem_table_id CFL oem_revision 538378241
[    5.495491] snd_soc_skl 0000:00:1f.3: No matching I2S machine driver found
[    5.495533] snd_soc_skl 0000:00:1f.3: dsp registration status=0
[    5.495572] snd_soc_skl 0000:00:1f.3: Clearing TCSEL
[    5.500266] snd_soc_skl 0000:00:1f.3: codec #0 probed OK: 10ec0285

dmesg-sst-dyndbg.log

sof with dyndbg
dmesg-sof-dyndbg.log

[plbossart]

Extracting the useful information from the SOF boot

[    5.709545] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    5.709549] sof-audio-pci 0000:00:1f.3: status = 0x00000000 panic = 0x00000000
[    5.709566] sof-audio-pci 0000:00:1f.3: extended rom status:  0x6000021 0x0 0x0 0x0 0x0 0x0 0x183011b 0x0
[    5.709568] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    5.709601] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    5.709631] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    5.709637] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[    5.709641] sof-audio-pci 0000:00:1f.3: Attempting iteration 1 of Core En/ROM load...
[    5.709649] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[    5.709683] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[    5.709689] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[    5.709698] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[    5.710243] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
[    5.710248] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
[    6.010564] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 timedout
[    6.010566] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    6.010569] sof-audio-pci 0000:00:1f.3: status = 0x00000000 panic = 0x00000000
[    6.010582] sof-audio-pci 0000:00:1f.3: extended rom status:  0x6000021 0x0 0x0 0x0 0x0 0x0 0x183011b 0x0
[    6.010584] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    6.010589] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    6.010594] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    6.010596] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[    6.010597] sof-audio-pci 0000:00:1f.3: Attempting iteration 2 of Core En/ROM load...
[    6.010599] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[    6.010613] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[    6.010617] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[    6.010625] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[    6.011242] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
[    6.011248] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
[    6.311586] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 timedout
[    6.311587] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout HDA_DSP_SRAM_REG_ROM_STATUS read
[    6.311611] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    6.311662] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
[    6.311884] sof-audio-pci 0000:00:1f.3: error: extended rom status:  0x6000021 0x0 0x0 0x0 0x0 0x0 0x183011b 0x0
[    6.311910] sof-audio-pci 0000:00:1f.3: unknown ROM status value 06000021
[    6.311984] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    6.312062] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[    6.312088] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[    6.312089] sof-audio-pci 0000:00:1f.3: error: dsp init failed after 3 attempts with err: -110
[    6.312139] sof-audio-pci 0000:00:1f.3: ROM error=0xffffffff: FW status=0xffffffff
[    6.312212] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[    6.312257] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
[    6.312440] sof-audio-pci 0000:00:1f.3: error: extended rom status:  0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff 0xffffffff
[    6.312463] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[    6.312486] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[    6.312486] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware -110
[    6.362775] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1c003c timedout
[    6.362776] sof-audio-pci 0000:00:1f.3: error: hda_dsp_core_reset_enter: timeout on HDA_DSP_REG_ADSPCS read
[    6.362777] sof-audio-pci 0000:00:1f.3: error: dsp core reset failed: core_mask f
[    6.363011] sof-audio-pci 0000:00:1f.3: error: sof_probe_work failed err: -110

@ranj063 @jajanusz do those initial boot codes mean anything to you? Also wondering why in the error case we get a -1?

[plbossart]

@chmooreck the SST log does not seem to provide any useful info, did you enable SND_SOC_INTEL_SKYLAKE_HDAUDIO_CODEC in your .config? Also when you use SST you likely need to disable SOF completely.

Edit: you also need SND_SOC_INTEL_SKL_HDA_DSP_GENERIC_MACH