MTL: DSP panic with firmware 2.10.1

[plbossart]

Reported by @ImDevinC and forked from #4880 (comment)

Just confirmed I'm on 6.10 and while the audio device shows up now, I do not get any audio. Here's what I'm seeing in journalctl for "sof-". My dmesg buffer is too large to go back to the beginning because there is a bunch of spam messages about the audio card (I'll put those below)
Also, since this issue is already closed, let me know if it would be better to create a new one with this info

Jul 21 09:51:06.879342 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: enabling device (0000 -> 0002)
Jul 21 09:51:06.886182 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if 0x040100
Jul 21 09:51:06.886285 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: bound 0000:00:02.0 (ops i915_audio_component_bind_ops [i915])
Jul 21 09:51:06.889348 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: use msi interrupt mode
Jul 21 09:51:06.899343 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: DMICs detected in NHLT tables: 2
Jul 21 09:51:06.899515 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: hda codecs found, mask 4
Jul 21 09:51:06.902678 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Firmware paths/files for ipc type 1:
Jul 21 09:51:06.902832 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3:  Firmware file:     intel/sof-ipc4/mtl/sof-mtl.ri
Jul 21 09:51:06.902956 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3:  Firmware lib path: intel/sof-ipc4-lib/mtl
Jul 21 09:51:06.903065 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3:  Topology file:     intel/sof-ace-tplg/sof-mtl-rt711-l0-rt1316-l3-2ch.tplg
Jul 21 09:51:06.903176 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Loaded firmware library: ADSPFW, version: 2.10.0.1
Jul 21 09:51:07.026011 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Booted firmware version: 2.10.0.1
Jul 21 09:51:07.036010 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Topology: ABI 3:29:0 Kernel ABI 3:23:0
Jul 21 09:51:07.070351 bean kernel: input: sof-soundwire Headset Jack as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card1/input23
Jul 21 09:51:07.070376 bean kernel: input: sof-soundwire HDMI/DP,pcm=5 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card1/input24
Jul 21 09:51:07.070389 bean kernel: input: sof-soundwire HDMI/DP,pcm=6 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card1/input25
Jul 21 09:51:07.070402 bean kernel: input: sof-soundwire HDMI/DP,pcm=7 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card1/input26
Jul 21 09:52:50.079336 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ DSP dump start ]------------
Jul 21 09:52:50.079656 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: DSP panic!
Jul 21 09:52:50.079800 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: fw_state: SOF_FW_BOOT_COMPLETE (7)
Jul 21 09:52:50.079926 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: 0x50000005: module: ROM_EXT, state: FW_ENTERED, running
Jul 21 09:52:50.080043 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Firmware state: 0x5, status/error code: 0x0
Jul 21 09:52:50.080154 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Unknown toolchain is used
Jul 21 09:52:50.080266 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: DSP Firmware Oops
Jul 21 09:52:50.080396 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: Exception Cause: AllocaCause, MOVSP instruction, if caller’s registers are not in the register file
Jul 21 09:52:50.080514 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: EXCCAUSE 0x00000005 EXCVADDR 0x00000000 PS       0x00060e20 SAR     0x0000000c
Jul 21 09:52:50.080625 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: EPC1     0xa00727e5 EPC2     0x00000000 EPC3     0x00000000 EPC4    0x00000000
Jul 21 09:52:50.080738 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: EPC5     0x00000000 EPC6     0x00000000 EPC7     0x00000000 DEPC    0x00000000
Jul 21 09:52:50.080847 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: EPS2     0x00000000 EPS3     0x00000000 EPS4     0x00000000 EPS5    0x00000000
Jul 21 09:52:50.080952 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: EPS6     0x00000000 EPS7     0x00000000 INTENABL 0x00000000 INTERRU 0x00000000
Jul 21 09:52:50.081057 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: stack dump from 0x00000000
Jul 21 09:52:50.081168 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: AR registers:
Jul 21 09:52:50.081278 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: 0x0: a004b5d5 a0102f00 00000000 4011b440
Jul 21 09:52:50.081390 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: 0x10: a011b4c0 00000018 40107730 a0102f00
Jul 21 09:52:50.081498 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: 0x20: a005bf99 a0102ec0 40107730 a00613d8
Jul 21 09:52:50.081605 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: 0x30: a005bf99 a0102ec0 40107730 a00613d8
Jul 21 09:52:50.081711 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ DSP dump end ]------------
Jul 21 09:52:50.586371 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc timed out for 0xe030003|0xc00
Jul 21 09:52:50.586696 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ IPC dump start ]------------
Jul 21 09:52:50.586875 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Host IPC initiator: 0x8e030003|0xc00|0x0, target: 0x1b0a0000|0x0|0x0, ctl: 0x3
Jul 21 09:52:50.587031 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ IPC dump end ]------------
Jul 21 09:52:50.587179 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: IPC timeout
Jul 21 09:52:50.587333 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
Jul 21 09:52:50.587503 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0xe010003|0x0 failed: -19
Jul 21 09:52:50.587652 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -19
Jul 21 09:52:50.587835 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x13000003|0x1 failed: -19
Jul 21 09:52:50.587985 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to pause all pipelines
Jul 21 09:52:50.588129 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -19
Jul 21 09:52:50.588295 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x46000002|0x3 failed: -19
Jul 21 09:52:50.588442 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to unbind modules mixin.0.1:0 -> mixout.1.1:0
Jul 21 09:52:50.588598 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x12000000|0x0 failed: -19
Jul 21 09:52:50.588742 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to free pipeline widget pipeline.0
Jul 21 09:52:50.588884 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x12010000|0x0 failed: -19
Jul 21 09:52:50.589032 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to free pipeline widget pipeline.1
Jul 21 09:52:50.589176 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Failed to free connected widgets
Jul 21 09:52:50.589346 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: sof_pcm_stream_free: sof_widget_list_free failed -19
Jul 21 09:52:50.589496 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_prepare on 0000:00:1f.3: -19
Jul 21 09:52:50.589899 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x13000003|0x1 failed: -19
Jul 21 09:52:50.590047 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to pause all pipelines
Jul 21 09:52:50.590190 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -19
Jul 21 09:52:50.590351 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x46010002|0x10003 failed: -19
Jul 21 09:52:50.590499 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to unbind modules mixin.20.1:0 -> mixout.21.1:0
Jul 21 09:52:50.590639 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x12020000|0x0 failed: -19
Jul 21 09:52:50.590778 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to free pipeline widget pipeline.20
Jul 21 09:52:50.590919 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0x12030000|0x0 failed: -19
Jul 21 09:52:50.591069 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to free pipeline widget pipeline.21
Jul 21 09:52:50.591208 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Failed to free connected widgets
Jul 21 09:52:50.591344 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: sof_pcm_stream_free: sof_widget_list_free failed -19
Jul 21 09:52:50.591481 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_prepare on 0000:00:1f.3: -19
Jul 21 09:52:50.591663 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc4_tx_msg_unlocked: ipc message send for 0xe010002|0x0 failed: -19
Jul 21 09:52:50.591804 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -19
Jul 21 09:52:50.591965 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: sof_pcm_stream_free: pcm_ops hw_free failed -19
Jul 21 09:52:50.592127 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_prepare on 0000:00:1f.3: -19
Jul 21 09:52:50.592397 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to create module pipeline.0
Jul 21 09:52:50.592628 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Failed to set up connected widgets
Jul 21 09:52:50.592779 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: failed widget list set up for pcm 0 dir 0
Jul 21 09:52:50.593003 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: set pcm hw_params after resume
Jul 21 09:52:50.593209 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_prepare on 0000:00:1f.3: -19
Jul 21 09:52:50.593352 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: failed to create module pipeline.20
Jul 21 09:52:50.593461 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Failed to set up connected widgets
Jul 21 09:52:50.593565 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: failed widget list set up for pcm 2 dir 0
Jul 21 09:52:50.593668 bean kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: error: set pcm hw_params after resume
....

Repeated messages in dmesg

[  510.927461]  Speaker: ASoC: error at __soc_pcm_prepare on Speaker: -19
[  510.927464]  Speaker: ASoC: error at dpcm_fe_dai_prepare on Speaker: -19
[  510.932642] sof-audio-pci-intel-mtl 0000:00:1f.3: failed to create module pipeline.0
[  510.932645] sof-audio-pci-intel-mtl 0000:00:1f.3: Failed to set up connected widgets
[  510.932647] sof-audio-pci-intel-mtl 0000:00:1f.3: error: failed widget list set up for pcm 0 dir 0
[  510.932649] sof-audio-pci-intel-mtl 0000:00:1f.3: error: set pcm hw_params after resume
[  510.932650] sof-audio-pci-intel-mtl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_prepare on 0000:00:1f.3: -19
[  510.932652]  Jack Out: ASoC: error at __soc_pcm_prepare on Jack Out: -19
[  510.932654]  Jack Out: ASoC: error at dpcm_fe_dai_prepare on Jack Out: -19

[ujfalusi]

@ImDevinC, can you add the sof-dyndbg.txt as /etc/modprobe.d/sof-dyndbg.conf and share the resulting kernel log?

Also, can you attach the output of alsa-info before logging in to DE.

FWIW, on my Dell Precision 5690 I have installed sof-firmware 2024.06-1 and linux 6.9.10-arch1-1 (I'm using Artix and KDE/Plasma). I don't see the firmware panic in this setup but I don't have NVIDIA dGPU in this machine.

@CNG, you have the same machine, did you also encountered firmware crash?

[ImDevinC]

Here is the attached info
alsa-info.txt
sof-prelogin.txt

Some other things I noticed while poking around:

• The crash doesn't seem to happen immediately, even after DE login or even after trying to play audio. It happens if I try to mess with the audio settings (IE: in alsamixer or pavucontrol)
• Even playing audio doesn't seem to cause the crash
• In alsamixer, my speaker can be muted and unmuted, but there is no volume slider

Small update
I changed something that allowed audio to work. But when I rebooted, I no longer have audio and can't figure out what I did. Still triaging that.
Once audio worked, changing my audio profile in pavucontrol from Hifi to Pro Audio caused the dmesg errors again

[ujfalusi]

@ImDevinC, thank you. The kernel log is missing the driver probing section, but if you paste the output of sudo cat /sys/kernel/debug/sof/fw_profile/* we will have the needed details from there.
[1] It would help to have the log as well when the fw panic happens.

If you captured the log [1], then there is one thing which might work around the firmware panic but it will disable the onboard DMICs...
Look for the line containing snd_sof_intel_hda_generic in the sof-dyndbg.conf and append dmic_num=0 to have:

options snd_sof_intel_hda_generic dyndbg=+pmf dmic_num=0

and reboot.
Now try to reproduce the issue. Either if it avoids or makes no difference will help to narrow down the issue along with the kernel log which contains the events around the firmware panic.

As for volume controls, try Main Amplifier and Amplifier

[ImDevinC]

Before I post the logs, found some interesting points:

• Opening pavucontrol causes the panic. If I don't open pavucontrol, the panic doesn't happen.
• If I set my audio profile to Play HiFi quality music in pavucontrol and reboot, my audio works (and works on every reboot)
• If I set my audio profile to Pro audio in pavucontrol and reboot, my audio does not work (but will work if I set it back to Play HiFi quality music and reboot)
• Setting dmic_num=0 didn't change anything, panic still happens

Here's the logs you asked for. I'm cutoff the dmesg.txt file after a certain point becaues the file was growing very rapidly with the same error messages repeated over and over

sudo cat /sys/kernel/debug/sof/fw_profile/*
intel/sof-ipc4-lib/mtl
sof-mtl.ri
intel/sof-ipc4/mtl
1
sof-mtl-rt711-l0-rt1316-l3-2ch.tplg
intel/sof-ace-tplg

dmesg.txt

[plbossart]

looks like there's a sequence of trigger/free/prepare that doesn't go so well for iDISP2/HDMI2

[   45.411947] snd_sof:sof_pcm_trigger: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: trigger stream 6 dir 0 cmd 0
[   45.411949] snd_sof:sof_ipc4_trigger_pipelines: sof-audio-pci-intel-mtl 0000:00:1f.3: trigger cmd: 0 state: 3
[   45.411953] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0xe010103|0x0
[   45.412789] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x2e000000|0x0
[   45.412800] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0xe010103|0x0
[   45.412810] snd_sof_intel_hda_common:hda_dai_trigger: sof-audio-pci-intel-mtl 0000:00:1f.3: cmd=0 dai iDisp2 Pin direction 0
[   45.412856] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-mtl 0000:00:1f.3: FW Poll Status: reg[0x220]=0x440000 successful
[   45.412860] snd_sof:sof_ipc4_trigger_pipelines: sof-audio-pci-intel-mtl 0000:00:1f.3: trigger cmd: 0 state: 2
[   45.412862] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0xe000103|0x0
[   45.413200] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x2e000000|0x0
[   45.413217] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0xe000103|0x0
[   45.413241] snd_sof:sof_widget_free_unlocked: sof-audio-pci-intel-mtl 0000:00:1f.3: widget host-copier.6.playback freed
[   45.413244] snd_sof:sof_widget_free_unlocked: sof-audio-pci-intel-mtl 0000:00:1f.3: widget dai-copier.HDA.iDisp2.playback freed
[   45.413247] snd_sof:sof_pcm_prepare: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: prepare stream 6 dir 0
[   45.413250] snd_sof:sof_pcm_hw_params: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: hw params stream 6 dir 0
[   45.413255] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-mtl 0000:00:1f.3: FW Poll Status: reg[0x220]=0x40000 successful
[   45.413265] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-mtl 0000:00:1f.3: FW Poll Status: reg[0x220]=0x40000 successful
[   45.413268] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-mtl 0000:00:1f.3: period_bytes:0x8000
[   45.413270] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-mtl 0000:00:1f.3: periods:32
[   45.413282] snd_sof:sof_ipc4_prepare_copier_module: sof-audio-pci-intel-mtl 0000:00:1f.3: copier host-copier.6.playback, type 23
[   45.413285] snd_sof:sof_ipc4_prepare_copier_module: sof-audio-pci-intel-mtl 0000:00:1f.3: copier dai-copier.HDA.iDisp2.playback, type 27
[   45.413289] snd_sof:sof_widget_setup_unlocked: sof-audio-pci-intel-mtl 0000:00:1f.3: widget host-copier.6.playback setup complete
[   45.413291] snd_sof:sof_widget_setup_unlocked: sof-audio-pci-intel-mtl 0000:00:1f.3: widget dai-copier.HDA.iDisp2.playback setup complete
[   45.413464] snd_sof_intel_hda_common:hda_dai_trigger: sof-audio-pci-intel-mtl 0000:00:1f.3: cmd=1 dai iDisp2 Pin direction 0
[   45.413470] snd_sof:sof_pcm_trigger: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: trigger stream 6 dir 0 cmd 1
[   45.413472] snd_sof:sof_ipc4_trigger_pipelines: sof-audio-pci-intel-mtl 0000:00:1f.3: trigger cmd: 1 state: 4
[   45.413475] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0xe030003|0xc00
[   45.415162] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc rx      : 0x1b0a0000|0x0
[   45.415166] sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ DSP dump start ]------------
[   45.415170] sof-audio-pci-intel-mtl 0000:00:1f.3: DSP panic!
....
[   45.935987]  HDMI2: ASoC: trigger FE cmd: 1 failed: -110

[ImDevinC]

looks like there's a sequence of trigger/free/prepare that doesn't go so well for iDISP2/HDMI2

@plbossart is this just a note, or is there something you'd like me to do? Just making sure I don't leave something unanswered

[plbossart]

just a note @ImDevinC, we 're trying to figure out what sequence leads to the panic.

[ujfalusi]

The fix for the issue is on the kernel side: #5119