Open eighthave opened 1 year ago
@eighthave can you help us understand what you mean by "After a couple of days of running without reboot, the audio will stop working"
do you have audio playing non-stop, or just 'normal' usage with music/media/calls/notification? do you suspend the device and if yes in what mode? Or do you leave the device up-and-running, with audio suspended?
do you have audio playing non-stop, or just 'normal' usage with music/media/calls/notification?
It is a work laptop so pretty typical work usage:
do you suspend the device and if yes in what mode?
I use the default suspend setup from Debian/bookworm. The laptop goes to sleep automatically after a timeout, also when I close the lid. I close the laptop a couple of times a day. I believe that is this is the active suspend mode:
~ $ cat /sys/power/mem_sleep
[s2idle]
Or do you leave the device up-and-running, with audio suspended?
It is rarely running without sleep for more than a day.
I can't think of any turn-key solutions, I briefly looked and we have not had any reports of problems on power-up/down issues, but I am not sure we have a test that last several days either.
The only thing I can suggest is to add more information with dynamic debug, e.g. add this in a .conf file in /etc/modprobe.d/
# PCI
options snd_sof_pci dyndbg=+pmf
options snd_sof_pci_intel_tgl dyndbg=+pmf
# SOF internals
options snd_sof_intel_ipc dyndbg=+pmf
options snd_sof_intel_hda_common dyndbg=+pmf
options snd_sof_intel_hda dyndbg=+pmf
options snd_sof dyndbg=+pmf
This will be very verbose so you want a large buffer as well to keep track of the issues.
In case it wasn't clear, the crash seems to always happen when using the computer, not when suspended. Like I'm working away, and the music stops, and the music app's play/pause stops working.
I added the modprobe conf, I'll report back on the next crash.
In case it wasn't clear, the crash seems to always happen when using the computer, not when suspended. Like I'm working away, and the music stops, and the music app's play/pause stops working.
The dmesg logs seems to hint of an issue when restarting and powering-up the audio DSP. It would be a very different issue if the music stopped after a while with the DSP going in the weeds.
I added the modprobe conf, I'll report back on the next crash.
Thanks, let's see what happens and what we can figure out with more information.
It definitely happens during regular operation, not around sleep events. I know because I often work with music, and I'm in my flow, and the music just stops.
Ok, I upgraded to Linux 6.4~rc6 (Debian 1\~exp1) and it failed pretty much immediately after boot, but in a different way. Browser video playback and music player playback are stuck, that's familiar. But it didn't seem to give a crash dump this time. And there is some loop in dmesg. Here's output:
# grep -e sof -e snd -e pipewire /var/log/syslog |grep 2023-06-20T15
2023-06-20T15:13:01.690373+02:00 monolith pipewire[2296]: spa.alsa: opened:1 format:1 started:0
2023-06-20T15:13:01.690512+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: Device 'hw:sofsoundwire,5' closing
2023-06-20T15:13:01.690557+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: ALSA device open '_ucm0001.hw:sofsoundwire,5' playback
2023-06-20T15:13:01.690658+02:00 monolith kernel: [ 1209.684317] snd_sof:sof_pcm_close: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 5 dir 0
2023-06-20T15:13:01.710814+02:00 monolith kernel: [ 1209.704642] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: open stream 5 dir 0
2023-06-20T15:13:01.710825+02:00 monolith kernel: [ 1209.704649] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: period min 192 max 16384 bytes
2023-06-20T15:13:01.710826+02:00 monolith kernel: [ 1209.704653] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: period count 2 max 16
2023-06-20T15:13:01.710826+02:00 monolith kernel: [ 1209.704655] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: buffer max 65536 bytes
2023-06-20T15:13:01.712001+02:00 monolith pipewire[2296]: spa.alsa: enum_pcm_formats:
2023-06-20T15:13:01.712053+02:00 monolith pipewire[2296]: spa.alsa: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED
2023-06-20T15:13:01.712085+02:00 monolith pipewire[2296]: spa.alsa: FORMAT: S16_LE S24_LE S32_LE
2023-06-20T15:13:01.712107+02:00 monolith pipewire[2296]: spa.alsa: SUBFORMAT: STD
2023-06-20T15:13:01.712368+02:00 monolith pipewire[2296]: spa.alsa: SAMPLE_BITS: [16 32]
2023-06-20T15:13:01.712392+02:00 monolith pipewire[2296]: spa.alsa: FRAME_BITS: [32 64]
2023-06-20T15:13:01.712413+02:00 monolith pipewire[2296]: spa.alsa: CHANNELS: 2
2023-06-20T15:13:01.712437+02:00 monolith pipewire[2296]: spa.alsa: RATE: 48000
2023-06-20T15:13:01.712467+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_TIME: [500 85334)
2023-06-20T15:13:01.712489+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_SIZE: [24 4096]
2023-06-20T15:13:01.712513+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_BYTES: [192 16384]
2023-06-20T15:13:01.712535+02:00 monolith pipewire[2296]: spa.alsa: PERIODS: [2 16]
2023-06-20T15:13:01.712556+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_TIME: [1000 341334)
2023-06-20T15:13:01.712723+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_SIZE: [48 16384]
2023-06-20T15:13:01.712749+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_BYTES: [192 65536]
2023-06-20T15:13:01.712770+02:00 monolith pipewire[2296]: spa.alsa: TICK_TIME: ALL
2023-06-20T15:13:01.712792+02:00 monolith pipewire[2296]: spa.alsa: min:48000 max:48000 min-allowed:0 scale:1 interleave:1 all:0
2023-06-20T15:13:01.712823+02:00 monolith pipewire[2296]: spa.alsa: rate:48000 multi:1 card:48000 def:0
2023-06-20T15:13:01.712850+02:00 monolith pipewire[2296]: spa.alsa: channels (2 2) default:2 all:0
2023-06-20T15:13:01.712875+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: position 0 3
2023-06-20T15:13:01.712903+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: position 1 4
2023-06-20T15:13:01.712926+02:00 monolith pipewire[2296]: spa.alsa: opened:1 format:0 started:0
2023-06-20T15:13:01.712962+02:00 monolith pipewire[2296]: spa.alsa: spa_alsa_set_format:
2023-06-20T15:13:01.712985+02:00 monolith pipewire[2296]: spa.alsa: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED
2023-06-20T15:13:01.713055+02:00 monolith pipewire[2296]: spa.alsa: FORMAT: S16_LE S24_LE S32_LE
2023-06-20T15:13:01.713078+02:00 monolith pipewire[2296]: spa.alsa: SUBFORMAT: STD
2023-06-20T15:13:01.713100+02:00 monolith pipewire[2296]: spa.alsa: SAMPLE_BITS: [16 32]
2023-06-20T15:13:01.713123+02:00 monolith pipewire[2296]: spa.alsa: FRAME_BITS: [32 64]
2023-06-20T15:13:01.713146+02:00 monolith pipewire[2296]: spa.alsa: CHANNELS: 2
2023-06-20T15:13:01.713168+02:00 monolith pipewire[2296]: spa.alsa: RATE: 48000
2023-06-20T15:13:01.713191+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_TIME: [500 85334)
2023-06-20T15:13:01.713214+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_SIZE: [24 4096]
2023-06-20T15:13:01.713237+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_BYTES: [192 16384]
2023-06-20T15:13:01.713260+02:00 monolith pipewire[2296]: spa.alsa: PERIODS: [2 16]
2023-06-20T15:13:01.713283+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_TIME: [1000 341334)
2023-06-20T15:13:01.713308+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_SIZE: [48 16384]
2023-06-20T15:13:01.713330+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_BYTES: [192 65536]
2023-06-20T15:13:01.713352+02:00 monolith pipewire[2296]: spa.alsa: TICK_TIME: ALL
2023-06-20T15:13:01.713375+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: Stream parameters are 48000Hz fmt:S32_LE access:mmap-interleaved channels:2
2023-06-20T15:13:01.713406+02:00 monolith pipewire[2296]: spa.alsa: hw:sofsoundwire,5 (playback): format:S32_LE access:mmap-interleaved rate:48000 channels:2 buffer frames 8192, period frames 1024, periods 8, frame_size 8 headroom 0 start-delay:0 tsched:1
2023-06-20T15:13:01.714726+02:00 monolith kernel: [ 1209.705261] snd_sof_intel_hda_common:hda_link_dma_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: format_val=0x31, rate=48000, ch=2, format=10
2023-06-20T15:13:01.714732+02:00 monolith kernel: [ 1209.705292] snd_sof:sof_pcm_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: hw params stream 5 dir 0
2023-06-20T15:13:01.714733+02:00 monolith kernel: [ 1209.705321] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:01.714734+02:00 monolith kernel: [ 1209.705357] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:01.714735+02:00 monolith kernel: [ 1209.705365] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: period_bytes:0x2000
2023-06-20T15:13:01.714735+02:00 monolith kernel: [ 1209.705366] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: periods:8
2023-06-20T15:13:01.714736+02:00 monolith kernel: [ 1209.705398] snd_sof:ipc3_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x30100000
2023-06-20T15:13:02.239538+02:00 monolith pipewire[2296]: spa.alsa: set_hw_params: Connection timed out
2023-06-20T15:13:02.239895+02:00 monolith pipewire[2296]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__hw_sofsoundwire_5__sink-55) suspended -> error (Start error: Connection timed out)
2023-06-20T15:13:02.242741+02:00 monolith kernel: [ 1210.232928] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x30100000 (msg/reply size: 48/0)
2023-06-20T15:13:02.242769+02:00 monolith kernel: [ 1210.232951] sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
2023-06-20T15:13:02.242771+02:00 monolith kernel: [ 1210.232958] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to setup widget PIPELINE.6.HDA0.OUT
2023-06-20T15:13:02.242772+02:00 monolith kernel: [ 1210.232965] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
2023-06-20T15:13:02.242773+02:00 monolith kernel: [ 1210.232975] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 5 dir 0
2023-06-20T15:13:02.242774+02:00 monolith kernel: [ 1210.232983] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
2023-06-20T15:13:02.242780+02:00 monolith kernel: [ 1210.233123] snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 5 dir 0
2023-06-20T15:13:02.249341+02:00 monolith pipewire[2296]: spa.alsa: opened:1 format:1 started:0
2023-06-20T15:13:02.249435+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: Device 'hw:sofsoundwire,5' closing
2023-06-20T15:13:02.249476+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: ALSA device open '_ucm0001.hw:sofsoundwire,5' playback
2023-06-20T15:13:02.250711+02:00 monolith kernel: [ 1210.243405] snd_sof:sof_pcm_close: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 5 dir 0
2023-06-20T15:13:02.275514+02:00 monolith pipewire[2296]: spa.alsa: enum_pcm_formats:
2023-06-20T15:13:02.275654+02:00 monolith pipewire[2296]: spa.alsa: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED
2023-06-20T15:13:02.275709+02:00 monolith pipewire[2296]: spa.alsa: FORMAT: S16_LE S24_LE S32_LE
2023-06-20T15:13:02.275753+02:00 monolith pipewire[2296]: spa.alsa: SUBFORMAT: STD
2023-06-20T15:13:02.275903+02:00 monolith pipewire[2296]: spa.alsa: SAMPLE_BITS: [16 32]
2023-06-20T15:13:02.275949+02:00 monolith pipewire[2296]: spa.alsa: FRAME_BITS: [32 64]
2023-06-20T15:13:02.275990+02:00 monolith pipewire[2296]: spa.alsa: CHANNELS: 2
2023-06-20T15:13:02.276031+02:00 monolith pipewire[2296]: spa.alsa: RATE: 48000
2023-06-20T15:13:02.276068+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_TIME: [500 85334)
2023-06-20T15:13:02.276107+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_SIZE: [24 4096]
2023-06-20T15:13:02.276148+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_BYTES: [192 16384]
2023-06-20T15:13:02.276184+02:00 monolith pipewire[2296]: spa.alsa: PERIODS: [2 16]
2023-06-20T15:13:02.276223+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_TIME: [1000 341334)
2023-06-20T15:13:02.276261+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_SIZE: [48 16384]
2023-06-20T15:13:02.276299+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_BYTES: [192 65536]
2023-06-20T15:13:02.276344+02:00 monolith pipewire[2296]: spa.alsa: TICK_TIME: ALL
2023-06-20T15:13:02.276383+02:00 monolith pipewire[2296]: spa.alsa: min:48000 max:48000 min-allowed:0 scale:1 interleave:1 all:0
2023-06-20T15:13:02.276427+02:00 monolith pipewire[2296]: spa.alsa: rate:48000 multi:1 card:48000 def:0
2023-06-20T15:13:02.276467+02:00 monolith pipewire[2296]: spa.alsa: channels (2 2) default:2 all:0
2023-06-20T15:13:02.276505+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: position 0 3
2023-06-20T15:13:02.276546+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: position 1 4
2023-06-20T15:13:02.276584+02:00 monolith pipewire[2296]: spa.alsa: opened:1 format:0 started:0
2023-06-20T15:13:02.276623+02:00 monolith pipewire[2296]: spa.alsa: spa_alsa_set_format:
2023-06-20T15:13:02.276711+02:00 monolith pipewire[2296]: spa.alsa: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED
2023-06-20T15:13:02.276749+02:00 monolith pipewire[2296]: spa.alsa: FORMAT: S16_LE S24_LE S32_LE
2023-06-20T15:13:02.276787+02:00 monolith pipewire[2296]: spa.alsa: SUBFORMAT: STD
2023-06-20T15:13:02.276825+02:00 monolith pipewire[2296]: spa.alsa: SAMPLE_BITS: [16 32]
2023-06-20T15:13:02.276863+02:00 monolith pipewire[2296]: spa.alsa: FRAME_BITS: [32 64]
2023-06-20T15:13:02.278800+02:00 monolith kernel: [ 1210.269176] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: open stream 5 dir 0
2023-06-20T15:13:02.278816+02:00 monolith kernel: [ 1210.269187] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: period min 192 max 16384 bytes
2023-06-20T15:13:02.278817+02:00 monolith kernel: [ 1210.269192] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: period count 2 max 16
2023-06-20T15:13:02.278818+02:00 monolith kernel: [ 1210.269196] snd_sof:sof_pcm_open: sof-audio-pci-intel-tgl 0000:00:1f.3: buffer max 65536 bytes
2023-06-20T15:13:02.278819+02:00 monolith kernel: [ 1210.270153] snd_sof_intel_hda_common:hda_link_dma_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: format_val=0x31, rate=48000, ch=2, format=10
2023-06-20T15:13:02.278823+02:00 monolith kernel: [ 1210.270187] snd_sof:sof_pcm_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: hw params stream 5 dir 0
2023-06-20T15:13:02.278825+02:00 monolith kernel: [ 1210.270219] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:02.278828+02:00 monolith kernel: [ 1210.270271] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:02.278829+02:00 monolith kernel: [ 1210.270297] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: period_bytes:0x2000
2023-06-20T15:13:02.278830+02:00 monolith kernel: [ 1210.270301] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: periods:8
2023-06-20T15:13:02.278831+02:00 monolith kernel: [ 1210.270355] snd_sof:ipc3_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x30100000
2023-06-20T15:13:02.289008+02:00 monolith pipewire[2296]: spa.alsa: CHANNELS: 2
2023-06-20T15:13:02.289080+02:00 monolith pipewire[2296]: spa.alsa: RATE: 48000
2023-06-20T15:13:02.289140+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_TIME: [500 85334)
2023-06-20T15:13:02.289196+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_SIZE: [24 4096]
2023-06-20T15:13:02.289251+02:00 monolith pipewire[2296]: spa.alsa: PERIOD_BYTES: [192 16384]
2023-06-20T15:13:02.289305+02:00 monolith pipewire[2296]: spa.alsa: PERIODS: [2 16]
2023-06-20T15:13:02.289367+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_TIME: [1000 341334)
2023-06-20T15:13:02.289428+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_SIZE: [48 16384]
2023-06-20T15:13:02.289484+02:00 monolith pipewire[2296]: spa.alsa: BUFFER_BYTES: [192 65536]
2023-06-20T15:13:02.289539+02:00 monolith pipewire[2296]: spa.alsa: TICK_TIME: ALL
2023-06-20T15:13:02.289595+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: Stream parameters are 48000Hz fmt:S32_LE access:mmap-interleaved channels:2
2023-06-20T15:13:02.289656+02:00 monolith pipewire[2296]: spa.alsa: hw:sofsoundwire,5 (playback): format:S32_LE access:mmap-interleaved rate:48000 channels:2 buffer frames 8192, period frames 1024, periods 8, frame_size 8 headroom 0 start-delay:0 tsched:1
2023-06-20T15:13:02.784548+02:00 monolith pipewire[2296]: spa.alsa: set_hw_params: Connection timed out
2023-06-20T15:13:02.786879+02:00 monolith kernel: [ 1210.776971] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x30100000 (msg/reply size: 48/0)
2023-06-20T15:13:02.786910+02:00 monolith kernel: [ 1210.777015] sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
2023-06-20T15:13:02.786914+02:00 monolith kernel: [ 1210.777030] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to setup widget PIPELINE.6.HDA0.OUT
2023-06-20T15:13:02.786915+02:00 monolith kernel: [ 1210.777044] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
2023-06-20T15:13:02.786920+02:00 monolith kernel: [ 1210.777061] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 5 dir 0
2023-06-20T15:13:02.786922+02:00 monolith kernel: [ 1210.777078] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
2023-06-20T15:13:02.786931+02:00 monolith kernel: [ 1210.777319] snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 5 dir 0
2023-06-20T15:13:02.792518+02:00 monolith pipewire[2296]: pw.link: 0x55b1416c6400: one of the nodes is in error out:suspended in:error
2023-06-20T15:13:02.792664+02:00 monolith pipewire[2296]: pw.link: 0x55b1417d7020: one of the nodes is in error out:suspended in:error
@eighthave what endpoint are you using for playback when it fails ? IIUC pipewire logs are showing soundwire ALSA device but kernel logs appear to show HDA output. @plbossart any thoughts ?
2023-06-20T15:13:01.713375+02:00 monolith pipewire[2296]: spa.alsa: 0x55b1413cb5d8: Stream parameters are 48000Hz fmt:S32_LE access:mmap-interleaved channels:2
2023-06-20T15:13:01.713406+02:00 monolith pipewire[2296]: spa.alsa: hw:sofsoundwire,5 (playback): format:S32_LE access:mmap-interleaved rate:48000 channels:2 buffer frames 8192, period frames 1024, periods 8, frame_size 8 headroom 0 start-delay:0 tsched:1
2023-06-20T15:13:01.714726+02:00 monolith kernel: [ 1209.705261] snd_sof_intel_hda_common:hda_link_dma_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: format_val=0x31, rate=48000, ch=2, format=10
2023-06-20T15:13:01.714732+02:00 monolith kernel: [ 1209.705292] snd_sof:sof_pcm_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: hw params stream 5 dir 0
2023-06-20T15:13:01.714733+02:00 monolith kernel: [ 1209.705321] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:01.714734+02:00 monolith kernel: [ 1209.705357] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x40000 successful
2023-06-20T15:13:01.714735+02:00 monolith kernel: [ 1209.705365] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: period_bytes:0x2000
2023-06-20T15:13:01.714735+02:00 monolith kernel: [ 1209.705366] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-tgl 0000:00:1f.3: periods:8
2023-06-20T15:13:01.714736+02:00 monolith kernel: [ 1209.705398] snd_sof:ipc3_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x30100000
2023-06-20T15:13:02.239538+02:00 monolith pipewire[2296]: spa.alsa: set_hw_params: Connection timed out
2023-06-20T15:13:02.239895+02:00 monolith pipewire[2296]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__hw_sofsoundwire_5__sink-55) suspended -> error (Start error: Connection timed out)
2023-06-20T15:13:02.242741+02:00 monolith kernel: [ 1210.232928] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x30100000 (msg/reply size: 48/0)
2023-06-20T15:13:02.242769+02:00 monolith kernel: [ 1210.232951] sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
2023-06-20T15:13:02.242771+02:00 monolith kernel: [ 1210.232958] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to setup widget PIPELINE.6.HDA0.OUT
Likely something happening over HDMI @lgirdwood, but that would be very different to the initial issue reported.
Likely something happening over HDMI @lgirdwood, but that would be very different to the initial issue reported.
Ack, I was thinking the same. @eighthave btw, do you have Nvidia GFX ? as NV driver has caused integration issues in the past.
Hmm, this audio freeze/crash was happening when I was using the built-in headphone jack for sure. Recently, I started using the HDMI out sometimes, but I can't say definitively whether it happened while I was using HDMI out. Once it does happen, the audio is stuck and does not work until I reboot, regardless of which output I select. I'll stick with the headphone jack and built-in speakers for now to narrow things down.
$ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: sofsoundwire [sof-soundwire], device 0: Jack Out (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofsoundwire [sof-soundwire], device 2: Speaker (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofsoundwire [sof-soundwire], device 5: HDMI 1 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofsoundwire [sof-soundwire], device 6: HDMI 2 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofsoundwire [sof-soundwire], device 7: HDMI 3 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofsoundwire [sof-soundwire], device 31: Jack Out DeepBuffer (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
I chose this Dell 9720 specifically because it has only Intel graphics, no nvidia. I've had too many bad experiences with nvidia. Maybe this is helpful:
$ lspci
00:00.0 Host bridge: Intel Corporation Device 4621 (rev 02)
00:02.0 VGA compatible controller: Intel Corporation Alder Lake-P Integrated Graphics Controller (rev 0c)
00:04.0 Signal processing controller: Intel Corporation Alder Lake Innovation Platform Framework Processor Participant (rev 02)
00:06.0 PCI bridge: Intel Corporation 12th Gen Core Processor PCI Express x4 Controller #0 (rev 02)
00:07.0 PCI bridge: Intel Corporation Alder Lake-P Thunderbolt 4 PCI Express Root Port #0 (rev 02)
00:07.1 PCI bridge: Intel Corporation Alder Lake-P Thunderbolt 4 PCI Express Root Port thesofproject/sof#1 (rev 02)
00:07.2 PCI bridge: Intel Corporation Alder Lake-P Thunderbolt 4 PCI Express Root Port thesofproject/sof#2 (rev 02)
00:07.3 PCI bridge: Intel Corporation Alder Lake-P Thunderbolt 4 PCI Express Root Port thesofproject/sof#3 (rev 02)
00:08.0 System peripheral: Intel Corporation 12th Gen Core Processor Gaussian & Neural Accelerator (rev 02)
00:0d.0 USB controller: Intel Corporation Alder Lake-P Thunderbolt 4 USB Controller (rev 02)
00:0d.2 USB controller: Intel Corporation Alder Lake-P Thunderbolt 4 NHI #0 (rev 02)
00:0d.3 USB controller: Intel Corporation Alder Lake-P Thunderbolt 4 NHI thesofproject/sof#1 (rev 02)
00:12.0 Serial controller: Intel Corporation Alder Lake-P Integrated Sensor Hub (rev 01)
00:14.0 USB controller: Intel Corporation Alder Lake PCH USB 3.2 xHCI Host Controller (rev 01)
00:14.2 RAM memory: Intel Corporation Alder Lake PCH Shared SRAM (rev 01)
00:14.3 Network controller: Intel Corporation Alder Lake-P PCH CNVi WiFi (rev 01)
00:15.0 Serial bus controller: Intel Corporation Alder Lake PCH Serial IO I2C Controller #0 (rev 01)
00:15.1 Serial bus controller: Intel Corporation Alder Lake PCH Serial IO I2C Controller thesofproject/sof#1 (rev 01)
00:16.0 Communication controller: Intel Corporation Alder Lake PCH HECI Controller (rev 01)
00:1c.0 PCI bridge: Intel Corporation Device 51bb (rev 01)
00:1f.0 ISA bridge: Intel Corporation Alder Lake PCH eSPI Controller (rev 01)
00:1f.3 Multimedia audio controller: Intel Corporation Alder Lake PCH-P High Definition Audio Controller (rev 01)
00:1f.4 SMBus: Intel Corporation Alder Lake PCH-P SMBus Host Controller (rev 01)
00:1f.5 Serial bus controller: Intel Corporation Alder Lake-P PCH SPI Controller (rev 01)
01:00.0 Non-Volatile memory controller: SK hynix Platinum P41 NVMe Solid State Drive 2TB
aa:00.0 Unassigned class [ff00]: Realtek Semiconductor Co., Ltd. RTS5260 PCI Express Card Reader (rev 01)
I plan on upgrading the kernel as new versions are available in Debian/experimental, unless it would be better for this debugging process if I stayed on a certain version.
can you please attach the logs of 'alsa-info'? I wonder if this device is actually handled by the kernel.
I also vaguely remember seeing the initial error
[360057.708434] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_power_up: timeout on HDA_DSP_REG_ADSPCS read
in another issue. This isn't really a problem with the firmware but rather the driver side of things.
Here is a very lightly edited alsa-info
(for privacy)
alsa-info.txt.zip
@plbossart do you think the HDMI device IDs have any impact. i.e. on legacy HDA I see
aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: PCH [HDA Intel PCH], device 0: ALC3204 Analog [ALC3204 Analog]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 3: HDMI 0 [HDMI 0]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 7: HDMI 1 [HDMI 1]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 8: HDMI 2 [HDMI 2]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 9: HDMI 3 [HDMI 3]
Subdevices: 1/1
Subdevice #0: subdevice #0
I'm wondering if display code or userspace is expecting the above mapping (and perhaps dependencies are not enabled for FW) ?
@eighthave you removed the DMI "SKU Number" that's the main information I was looking for. We don't track product names, they are irrelevant.
Oops, OK, sorry. I thought those were those unique IDs that Dell makes. I see now they are not unique to my computer. So here's an unredacted version: alsa-info.txt.zip
No worries, completely understand the privacy concerns.
The device is supported, there's a quirk for it, however the logs show something is not quite right:
Components : 'HDA:8086281c,80860101,00100000 cfg-spk:2 cfg-amp:2 hs:rt711-sdca spk:rt1316 mic:rt715-sdca'
The quirk is this:
{
.callback = sof_sdw_quirk_cb,
.matches = {
DMI_MATCH(DMI_SYS_VENDOR, "Dell Inc"),
DMI_EXACT_MATCH(DMI_PRODUCT_SKU, "0AF0")
},
.driver_data = (void *)(SOF_SDW_TGL_HDMI |
RT711_JD2 |
SOF_SDW_FOUR_SPK),
},
and the code does this:
card->components = devm_kasprintf(card->dev, GFP_KERNEL,
"cfg-spk:%d cfg-amp:%d",
(sof_sdw_quirk & SOF_SDW_FOUR_SPK)
? 4 : 2, amp_num);
so I don't quite get how you end-up with 2 speakers.
I can see that the GNOME Settings don't show two speakers. For what its worth, I haven't been able to get audio input working either. I don't know if that's related. It does show up in GNOME Settings via Pipewire (this is all Debian/bookworm defaults). But neither the mic nor the headphone jack will ever receive sound.
Sorry, I was wrong, this device is not handled in the kernel so you end-up with random values.
System SKU: 0AFE is not listed in sound/soc/intel/boards/sof_sdw.c
Can you provide the result of
ls /sys/bus/soundwire/devices
that will tell us what your configuration is, thank you @eighthave
~ $ ls /sys/bus/soundwire/devices
sdw:0:025d:0711:01 sdw:2:025d:1316:01 sdw-master-0 sdw-master-2
sdw:1:025d:1316:01 sdw:3:025d:0714:01 sdw-master-1 sdw-master-3
I don't know if this fixes your issue @eighthave but at least the patch in PR thesofproject/linux#4463 should make the jack detection work a lot better. One day we'll get the list of all SKUs, hope springs eternal, etc.
I'm running Debian's 6.4.4 now, and I think the audio hasn't crashed? I do still get some glitches in the audio, like things sounding like they are going through a vocoder, e.g. Amplitude Modulation. It seems that stopping audio playback for a minute makes it go away. I had a glitch recently, here's the dmesg
log, donno if it'll be useful:
There's a known issue where distortions appear when a xrun happens, there was a patch from @ranj063 to correct this IIRC. see https://github.com/thesofproject/linux/pull/4484
Great! I'll track it. Let me know if you need any testing from me.
There's a known issue where distortions appear when a xrun happens, there was a patch from @ranj063 to correct this IIRC. see thesofproject/linux#4484
Hi, Sorry for the unrelated comment, but can you give an approximation for when this patch will be upstreamed into the mainline kernel? Like will the patch be available before 6.5 is promoted to stable, or will this be merged during the 6.6 cycle? Thank you.
@plbossart is this fix merged ? Can we close ?
I'm on 6.5.10 now and I haven't had this issue in the past couple of weeks. I was having with an earlier 6.5.x version I think, but it wasn't as severe. It would recover after a while, whereas before only a reboot would fix it. I think the recovery could have been related to when the laptop was put to sleep and woken up.
I'm OK with closing it or leaving it open. I'll try to continue to provide some concrete info as I can get it.
@eighthave we can leave it open for the next few weeks, would be good to get further testing.
Hello, I think I am in this boat but I am not sure. Starting a few weeks ago I noticed my computer was hanging on shutdown. I dont use audio that often, but I began noticing my speaker slider control would vanish. Sometimes It would boot with it already missing ( Had this issue almost a year ago and it was patched). Sometimes I would boot and it would be present, and then at some point during the use of the laptop it would vanish. When I started to put 2 and 2 together I thought maybe the old bug from over a year ago had come back. I black listed 'snd_sof_pci_intel_tgl' like I did a year ago so it would stop the kernel panics until a patch was found....well this time around it didnt solve the crashes.
I am not quite sure what info I can provide. I am not aware of all the commands to bring up all the info needed. I can boot up with or without sound working, use the laptop for a while and shutdown. Sometimes when I shutdown it will shutdown cleanly, sometimes it will kernel panic. I have not been able to isolate it to get it repeatable. Only reason I suspect sound is because the disappearing speaker volume slider and some SOF errors in the dmesg.
I have a Dell XPS 17 9720 with Nvidia Discrete graphics. Running Arch Linux, Kernel version 6.7.8-arch1-1.
journalctl -b | grep sof
Mar 03 19:55:36 archlinux kernel: software IO TLB: area num 32. Mar 03 19:55:36 archlinux kernel: PCI-DMA: Using software bounce buffering for IO (SWIOTLB) Mar 03 19:55:36 archlinux kernel: software IO TLB: mapped [mem 0x00000000536bf000-0x00000000576bf000] (64MB) Mar 03 19:55:36 archlinux kernel: integrity: Loaded X.509 cert 'Microsoft Windows Production PCA 2011: a92902398e16c49778cd90f99e4f9ae17c55af53' Mar 03 19:55:36 archlinux kernel: integrity: Loaded X.509 cert 'Microsoft Corporation UEFI CA 2011: 13adbf4309bd82709c8cd54f316ed522988a1bd4' Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100 Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: SoundWire enabled on CannonLake+ platform, using SOF driver Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: enabling device (0000 -> 0002) Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if 0x040100 Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: bound 0000:00:02.0 (ops i915_audio_component_bind_ops [i915]) Mar 03 19:55:36 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: use msi interrupt mode Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda codecs found, mask 4 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Firmware info: version 2:2:0-57864 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Firmware: ABI 3:22:1 Kernel ABI 3:23:0 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: unknown sof_ext_man header type 3 size 0x30 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Firmware info: version 2:2:0-57864 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Firmware: ABI 3:22:1 Kernel ABI 3:23:0 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: snd_soc_register_card failed -517 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: snd_soc_register_card failed -517 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: snd_soc_register_card failed -517 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: snd_soc_register_card failed -517 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: snd_soc_register_card failed -517 Mar 03 19:55:37 archlinux kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Topology: ABI 3:22:1 Kernel ABI 3:23:0 Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: ASoC: Parent card not yet available, widget card binding deferred Mar 03 19:55:37 archlinux kernel: sof_sdw sof_sdw: hda_dsp_hdmi_build_controls: no PCM in topology for HDMI converter 3 Mar 03 19:55:37 archlinux kernel: input: sof-soundwire Headset Jack as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card0/input19 Mar 03 19:55:37 archlinux kernel: input: sof-soundwire HDMI/DP,pcm=5 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card0/input20 Mar 03 19:55:37 archlinux kernel: input: sof-soundwire HDMI/DP,pcm=6 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card0/input21 Mar 03 19:55:37 archlinux kernel: input: sof-soundwire HDMI/DP,pcm=7 as /devices/pci0000:00/0000:00:1f.3/sof_sdw/sound/card0/input22 Mar 03 19:55:45 archlinux alsactl[1324]: Found hardware: "sof-soundwire" "Intel Alderlake-P HDMI" "HDA:8086281c,80860101,00100000 cfg-spk:4 cfg-amp:2 hs:rt711-sdca spk:rt1316 mic:rt715-sdca" "" "" Mar 03 19:55:54 archlinux kmix[1982]: adding "alsa_output.pci-0000_00_1f.3-platform-sof_sdw.stereo-fallback" "Alder Lake PCH-P High Definition Audio Controller Stereo" Mar 03 19:55:54 archlinux kmix[1982]: adding "alsa_output.pci-0000_00_1f.3-platform-sof_sdw.stereo-fallback" "Alder Lake PCH-P High Definition Audio Controller Stereo" Mar 03 19:55:54 archlinux plasmashell[1749]: org.kde.plasma.pulseaudio: No object for name "alsa_output.pci-0000_00_1f.3-platform-sof_sdw.stereo-fallback.monitor"
@changedsoul we are unable to provide feedback, your description of the issue mixes things that happen in userspace (volume slider disappearing - not sure what this means) and kernel panics that don't seem related to audio.
For what its worth, I was running Debian's 6.7.4 on the same machine, and I noticed no audio issues. (It does have graphics instability, but that's a separate issue...)
@plbossart Sorry for lack of info. Here is the original issue I had with sound : https://github.com/thesofproject/linux/issues/3772 This issue had been resolved in the past, but it seems the same symptoms are now present again. This is why I am thinking its a sound issue again. I have the same error messages in dmesg that I did back then.
As for the sound volume slider, I am in KDE. You click on the speaker icon in the lower right and it has volume sliders for adjusting speaker volume. When sound is working, these are present. When sound stop and kernel panic happens on shutdown, these volume sliders are gone. I dont know how they get there, auto detect or something? All I know is they vanish and then I have those errors in dmesg.
@eighthave
For what its worth, I was running Debian's 6.7.4 on the same machine, and I noticed no audio issues. (It does have graphics instability, but that's a separate issue...)
Im not really sure where to start. I dont know for sure if this is a sound issue. Maybe hardware? I just came here cause its similar issues to what I had before and I am hoping I can help track down the issue. If it is an issue with SOF I would be glad to help test and do what ever is needed to prove or disprove the issue.
After a while of not seeing this issue, perhaps because I was running Linux 6.7.4, I'm now seeing this kind of behavior again from time to time running Debian's bookworm-backports 6.6.13-1~bpo12+1 kernel. Right now, I cannot get sound out or in, and apps that try to use the audio just instantly freeze up. I have these messages in the kernel log:
[70577.832621] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70577.832642] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70577.832648] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70577.832652] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70577.832885] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70577.832893] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70577.832896] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70577.832899] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70582.843042] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70582.843062] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70582.843070] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70582.843075] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70582.843333] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70582.843343] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70582.843347] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70582.843350] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70587.853236] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70587.853254] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70587.853261] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70587.853265] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70587.853445] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70587.853452] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70587.853455] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70587.853458] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70592.865246] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70592.865269] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70592.865276] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70592.865282] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70592.865500] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70592.865507] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70592.865511] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70592.865514] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70597.876763] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70597.876786] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70597.876795] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70597.876802] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70597.877051] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70597.877060] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70597.877064] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70597.877068] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70602.885989] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70602.886005] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70602.886011] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70602.886015] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70602.886192] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70602.886199] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70602.886203] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70602.886205] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70607.894514] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70607.894528] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70607.894533] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70607.894537] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70607.894693] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70607.894699] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70607.894702] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70607.894704] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70612.903981] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70612.903996] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70612.904001] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70612.904005] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70612.904173] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70612.904179] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70612.904182] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70612.904185] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70617.912402] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70617.912415] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70617.912419] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70617.912423] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[70617.912556] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[70617.912561] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[70617.912563] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[70617.912565] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
Ok, I'm using 6.7.12+bpo-amd64 now, and I think it hasn't since I upgraded. I'll report back if it does happen again.
Unfortunately, it is back. This time with 6.7.12+bpo-amd64. The audio has locked up again. No audio will play. Apps that try to play audio get stuck. Here's dmesg:
# dmesg |grep -v tables
[194706.176771] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194706.176780] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194706.176782] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194706.176784] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194706.176838] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194706.176840] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194706.176841] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194706.176843] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194706.180283] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194706.180292] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194706.180295] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194706.180297] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194706.180376] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194706.180379] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194706.180380] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194706.180381] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194711.183472] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194711.183489] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194711.183495] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194711.183499] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194711.183637] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194711.183642] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194711.183645] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194711.183647] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194734.133591] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194734.133598] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194734.133600] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194734.133602] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194734.133650] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194734.133652] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194734.133653] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194734.133654] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194739.141347] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194739.141356] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194739.141358] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194739.141360] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[194739.141418] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[194739.141420] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[194739.141421] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[194739.141422] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198960.712433] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198960.712440] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198960.712442] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198960.712443] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198960.712482] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198960.712483] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198960.712484] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198960.712485] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198960.714408] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198960.714412] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198960.714413] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198960.714414] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198960.714448] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198960.714450] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198960.714450] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198960.714451] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198965.721374] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198965.721394] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198965.721401] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198965.721406] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198965.721576] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198965.721581] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198965.721584] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198965.721587] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198990.735684] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198990.735697] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198990.735702] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198990.735705] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198990.735810] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198990.735814] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198990.735817] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198990.735819] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198995.746511] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198995.746534] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198995.746542] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198995.746548] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[198995.746783] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[198995.746792] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[198995.746796] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[198995.746800] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199503.459795] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199503.459809] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199503.459814] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199503.459817] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199503.459916] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199503.459920] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199503.459922] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199503.459924] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199503.466504] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199503.466507] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199503.466508] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199503.466509] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199503.466537] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199503.466538] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199503.466538] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199503.466539] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199505.466934] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199505.466942] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199505.466944] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199505.466945] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199505.466988] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199505.466989] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199505.466990] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199505.466991] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199505.469349] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199505.469353] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199505.469354] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199505.469355] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199505.469388] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199505.469389] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199505.469390] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199505.469391] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199508.475131] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199508.475156] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199508.475164] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199508.475170] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199508.475398] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199508.475406] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199508.475411] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199508.475415] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199512.875924] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[199535.502615] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199535.502632] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199535.502638] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199535.502644] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199535.502825] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199535.502832] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199535.502836] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199535.502839] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199540.505424] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199540.505437] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199540.505442] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199540.505446] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[199540.505581] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
[199540.505587] SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
[199540.505590] Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
[199540.505592] Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
[200416.884564] Lockdown: fwupd: /dev/mem,kmem,port is restricted; see man kernel_lockdown.7
can you please add the entire log, if available? Also enable dynamic debug if possible with this file sof-dyndbg.conf.txt copied at /etc/modprobe.d/sof-dyndbg.conf (need large console buffer since it'll be rather verbose). Thanks
Good call, there is a stacktrace in there:
2024-06-05T06:53:49.952708+02:00 monolith kernel: [158517.260130] CPU: 2 PID: 118271 Comm: kworker/u32:3 Tainted: G W 6.7.12+bpo-amd64 thesofproject/sof#1 Debian 6.7.12-1~bpo12+1
2024-06-05T06:53:49.952708+02:00 monolith kernel: [158517.260135] Hardware name: Dell Inc. XPS 17 9720/0TW02W, BIOS 1.18.0 06/05/2023
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260138] Workqueue: events_unbound async_run_entry_fn
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260148] RIP: 0010:irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260152] Code: f6 ff d2 0f 1f 00 89 c5 85 c0 74 38 c7 83 84 00 00 00 01 00 00 00 e9 38 ff ff ff 44 89 e6 48 c7 c7 10 4c 8c 84 e8 0b 2c f6 ff <0f> 0b 31 ed
e9 20 ff ff ff 48 8b 43 38 31 ed 81 08 00 40 00 00 e9
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260156] RSP: 0018:ffffa76fa26c7d28 EFLAGS: 00010086
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260160] RAX: 0000000000000000 RBX: ffff92db15ab0200 RCX: 0000000000000027
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260163] RDX: ffff92de7f4a1408 RSI: 0000000000000001 RDI: ffff92de7f4a1400
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260165] RBP: 00000000ffffffea R08: 0000000000000000 R09: ffffa76fa26c7af8
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260167] R10: ffffa76fa26c7af0 R11: 0000000000000003 R12: 00000000000000c8
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260169] R13: 0000000000000000 R14: ffff92db06d209d8 R15: ffff92db022e8140
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260171] FS: 0000000000000000(0000) GS:ffff92de7f480000(0000) knlGS:0000000000000000
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260173] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260175] CR2: 00007fdc64020ce0 CR3: 00000001b0e20000 CR4: 0000000000f50ef0
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260178] PKRU: 55555554
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260179] Call Trace:
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260183] <TASK>
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260185] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260189] ? __warn+0x81/0x130
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260199] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260202] ? report_bug+0x171/0x1a0
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260208] ? handle_bug+0x41/0x70
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260215] ? exc_invalid_op+0x17/0x70
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260221] ? asm_exc_invalid_op+0x1a/0x20
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260231] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260234] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260239] hda_dsp_resume+0xdf/0x1d0 [snd_sof_intel_hda_common]
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260272] ? __pfx_pci_pm_resume+0x10/0x10
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260281] sof_resume.isra.0+0x77/0x2a0 [snd_sof]
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260322] ? __pfx_pci_pm_resume+0x10/0x10
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260328] dpm_run_callback+0x89/0x1e0
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260338] __device_resume+0xa5/0x250
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260341] async_resume+0x1d/0x30
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260344] async_run_entry_fn+0x31/0x130
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260350] process_one_work+0x17c/0x350
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260357] worker_thread+0x27b/0x3a0
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260362] ? __pfx_worker_thread+0x10/0x10
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260367] kthread+0xe5/0x120
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260371] ? __pfx_kthread+0x10/0x10
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260374] ret_from_fork+0x31/0x50
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260382] ? __pfx_kthread+0x10/0x10
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260385] ret_from_fork_asm+0x1b/0x30
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260395] </TASK>
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.260396] ---[ end trace 0000000000000000 ]---
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.261573] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.261586] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
2024-06-05T06:53:49.952731+02:00 monolith kernel: [158517.261590] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
2024-06-05T06:53:49.952731+02:00 monolith kernel: [158517.261606] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
more context points to some sort of suspend/resume issue
2024-06-05T06:53:49.952698+02:00 monolith kernel: [129364.903276] soundwire_intel soundwire_intel.link.3: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952698+02:00 monolith kernel: [129364.903299] soundwire_intel soundwire_intel.link.2: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952699+02:00 monolith kernel: [129364.903310] soundwire_intel soundwire_intel.link.1: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952699+02:00 monolith kernel: [129364.903321] soundwire_intel soundwire_intel.link.0: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952699+02:00 monolith kernel: [129366.079932] ACPI: EC: interrupt blocked
2024-06-05T06:53:49.952700+02:00 monolith kernel: [158516.810288] ACPI: EC: interrupt unblocked
2024-06-05T06:53:49.952700+02:00 monolith kernel: [158517.042249] sof-audio-pci-intel-tgl 0000:00:1f.3: Enabling runtime PM for inactive device with active children
2024-06-05T06:53:49.952700+02:00 monolith kernel: [158517.059896] nvme nvme0: 16/0/0 default/read/poll queues
2024-06-05T06:53:49.952701+02:00 monolith kernel: [158517.242571] i915 0000:00:02.0: [drm] GT0: GuC firmware i915/adlp_guc_70.bin version 70.5.1
2024-06-05T06:53:49.952701+02:00 monolith kernel: [158517.242575] i915 0000:00:02.0: [drm] GT0: HuC firmware i915/tgl_huc.bin version 7.9.3
2024-06-05T06:53:49.952702+02:00 monolith kernel: [158517.256858] i915 0000:00:02.0: [drm] GT0: HuC: authenticated for all workloads
2024-06-05T06:53:49.952702+02:00 monolith kernel: [158517.257905] i915 0000:00:02.0: [drm] GT0: GUC: submission enabled
2024-06-05T06:53:49.952703+02:00 monolith kernel: [158517.257908] i915 0000:00:02.0: [drm] GT0: GUC: SLPC enabled
2024-06-05T06:53:49.952703+02:00 monolith kernel: [158517.258464] i915 0000:00:02.0: [drm] GT0: GUC: RC enabled
2024-06-05T06:53:49.952703+02:00 monolith kernel: [158517.259856] ------------[ cut here ]------------
2024-06-05T06:53:49.952703+02:00 monolith kernel: [158517.259858] Unbalanced IRQ 200 wake disable
2024-06-05T06:53:49.952704+02:00 monolith kernel: [158517.259866] WARNING: CPU: 2 PID: 118271 at kernel/irq/manage.c:915 irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952707+02:00 monolith kernel: [158517.260020] ucsi_acpi intel_pmc_bxt processor_thermal_rapl snd typec_ucsi intel_rapl_common iTCO_vendor_support mei processor_thermal_wt_req watchdog typec rfkill soundcore processor_thermal_power_floor roles igen6_edac processor_thermal_mbox int3403_thermal int340x_thermal_zone hid_multitouch intel_hid intel_pmc_core int3400_thermal acpi_thermal_rel acpi_pad sparse_keymap acpi_tad ac evdev serio_raw nfsd auth_rpcgss nfs_acl lockd grace sunrpc msr loop efi_pstore configfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 btrfs blake2b_generic dm_crypt dm_mod efivarfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod hid_sensor_custom hid_sensor_hub intel_ishtp_hid i915 drm_buddy i2c_algo_bit nvme drm_display_helper crc32_pclmul nvme_core hid_generic cec crc32c_intel t10_pi rc_core xhci_pci i2c_hid_acpi ghash_clmulni_intel crc64_rocksoft_generic ttm i2c_hid xhci_hcd sha512_ssse3 crc64_rocksoft rtsx_pci_sdmmc crc_t10dif
2024-06-05T06:53:49.952707+02:00 monolith kernel: [158517.260102] drm_kms_helper hid sha512_generic crct10dif_generic usbcore mmc_core intel_lpss_pci crct10dif_pclmul video sha256_ssse3 i2c_i801 drm intel_ish_ipc intel_lpss thunderbolt crc64 psmouse rtsx_pci sha1_ssse3 intel_ishtp i2c_smbus idma64 usb_common crct10dif_common button battery wmi aesni_intel crypto_simd cryptd
2024-06-05T06:53:49.952708+02:00 monolith kernel: [158517.260130] CPU: 2 PID: 118271 Comm: kworker/u32:3 Tainted: G W 6.7.12+bpo-amd64 thesofproject/sof#1 Debian 6.7.12-1~bpo12+1
2024-06-05T06:53:49.952708+02:00 monolith kernel: [158517.260135] Hardware name: Dell Inc. XPS 17 9720/0TW02W, BIOS 1.18.0 06/05/2023
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260138] Workqueue: events_unbound async_run_entry_fn
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260148] RIP: 0010:irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952709+02:00 monolith kernel: [158517.260152] Code: f6 ff d2 0f 1f 00 89 c5 85 c0 74 38 c7 83 84 00 00 00 01 00 00 00 e9 38 ff ff ff 44 89 e6 48 c7 c7 10 4c 8c 84 e8 0b 2c f6 ff <0f> 0b 31 ed e9 20 ff ff ff 48 8b 43 38 31 ed 81 08 00 40 00 00 e9
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260156] RSP: 0018:ffffa76fa26c7d28 EFLAGS: 00010086
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260160] RAX: 0000000000000000 RBX: ffff92db15ab0200 RCX: 0000000000000027
2024-06-05T06:53:49.952710+02:00 monolith kernel: [158517.260163] RDX: ffff92de7f4a1408 RSI: 0000000000000001 RDI: ffff92de7f4a1400
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260165] RBP: 00000000ffffffea R08: 0000000000000000 R09: ffffa76fa26c7af8
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260167] R10: ffffa76fa26c7af0 R11: 0000000000000003 R12: 00000000000000c8
2024-06-05T06:53:49.952711+02:00 monolith kernel: [158517.260169] R13: 0000000000000000 R14: ffff92db06d209d8 R15: ffff92db022e8140
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260171] FS: 0000000000000000(0000) GS:ffff92de7f480000(0000) knlGS:0000000000000000
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260173] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2024-06-05T06:53:49.952712+02:00 monolith kernel: [158517.260175] CR2: 00007fdc64020ce0 CR3: 00000001b0e20000 CR4: 0000000000f50ef0
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260178] PKRU: 55555554
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260179] Call Trace:
2024-06-05T06:53:49.952713+02:00 monolith kernel: [158517.260183] <TASK>
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260185] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260189] ? __warn+0x81/0x130
2024-06-05T06:53:49.952714+02:00 monolith kernel: [158517.260199] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260202] ? report_bug+0x171/0x1a0
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260208] ? handle_bug+0x41/0x70
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260215] ? exc_invalid_op+0x17/0x70
2024-06-05T06:53:49.952715+02:00 monolith kernel: [158517.260221] ? asm_exc_invalid_op+0x1a/0x20
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260231] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260234] ? irq_set_irq_wake+0x155/0x1a0
2024-06-05T06:53:49.952716+02:00 monolith kernel: [158517.260239] hda_dsp_resume+0xdf/0x1d0 [snd_sof_intel_hda_common]
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260272] ? __pfx_pci_pm_resume+0x10/0x10
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260281] sof_resume.isra.0+0x77/0x2a0 [snd_sof]
2024-06-05T06:53:49.952717+02:00 monolith kernel: [158517.260322] ? __pfx_pci_pm_resume+0x10/0x10
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260328] dpm_run_callback+0x89/0x1e0
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260338] __device_resume+0xa5/0x250
2024-06-05T06:53:49.952718+02:00 monolith kernel: [158517.260341] async_resume+0x1d/0x30
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260344] async_run_entry_fn+0x31/0x130
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260350] process_one_work+0x17c/0x350
2024-06-05T06:53:49.952719+02:00 monolith kernel: [158517.260357] worker_thread+0x27b/0x3a0
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260362] ? __pfx_worker_thread+0x10/0x10
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260367] kthread+0xe5/0x120
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260371] ? __pfx_kthread+0x10/0x10
2024-06-05T06:53:49.952720+02:00 monolith kernel: [158517.260374] ret_from_fork+0x31/0x50
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260382] ? __pfx_kthread+0x10/0x10
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260385] ret_from_fork_asm+0x1b/0x30
2024-06-05T06:53:49.952721+02:00 monolith kernel: [158517.260395] </TASK>
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.260396] ---[ end trace 0000000000000000 ]---
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.261573] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
2024-06-05T06:53:49.952722+02:00 monolith kernel: [158517.261586] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
2024-06-05T06:53:49.952731+02:00 monolith kernel: [158517.261590] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
2024-06-05T06:53:49.952731+02:00 monolith kernel: [158517.261606] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
2024-06-05T06:53:49.952731+02:00 monolith kernel: [158517.262690] soundwire_intel soundwire_intel.link.1: Failed to power up link: -11
2024-06-05T06:53:49.952732+02:00 monolith kernel: [158517.262693] soundwire_intel soundwire_intel.link.1: intel_resume failed: -11
2024-06-05T06:53:49.952732+02:00 monolith kernel: [158517.262696] soundwire_intel soundwire_intel.link.1: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
2024-06-05T06:53:49.952733+02:00 monolith kernel: [158517.262703] soundwire_intel soundwire_intel.link.1: PM: failed to resume: error -11
2024-06-05T06:53:49.952733+02:00 monolith kernel: [158517.263792] soundwire_intel soundwire_intel.link.2: Failed to power up link: -11
2024-06-05T06:53:49.952733+02:00 monolith kernel: [158517.263795] soundwire_intel soundwire_intel.link.2: intel_resume failed: -11
2024-06-05T06:53:49.952733+02:00 monolith kernel: [158517.263797] soundwire_intel soundwire_intel.link.2: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
2024-06-05T06:53:49.952734+02:00 monolith kernel: [158517.263803] soundwire_intel soundwire_intel.link.2: PM: failed to resume: error -11
2024-06-05T06:53:49.952734+02:00 monolith kernel: [158517.264885] soundwire_intel soundwire_intel.link.3: Failed to power up link: -11
2024-06-05T06:53:49.952735+02:00 monolith kernel: [158517.264889] soundwire_intel soundwire_intel.link.3: intel_resume failed: -11
2024-06-05T06:53:49.952735+02:00 monolith kernel: [158517.264892] soundwire_intel soundwire_intel.link.3: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
2024-06-05T06:53:49.952735+02:00 monolith kernel: [158517.264899] soundwire_intel soundwire_intel.link.3: PM: failed to resume: error -11
Never seen this one before.
those lines are probably the most worrying, they point to a borked config where the traditional parent-child hierarchy is not followed. In theory a child device cannot suspend after its parent.
2024-06-05T06:53:49.952698+02:00 monolith kernel: [129364.903276] soundwire_intel soundwire_intel.link.3: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952698+02:00 monolith kernel: [129364.903299] soundwire_intel soundwire_intel.link.2: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952699+02:00 monolith kernel: [129364.903310] soundwire_intel soundwire_intel.link.1: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952699+02:00 monolith kernel: [129364.903321] soundwire_intel soundwire_intel.link.0: intel_suspend: invalid config: parent is suspended
2024-06-05T06:53:49.952700+02:00 monolith kernel: [158517.042249] sof-audio-pci-intel-tgl 0000:00:1f.3: Enabling runtime PM for inactive device with active children
I have a hunch that this state happens only after change the ALSA settings to enable the built-in microphone. The built-in microphone does not work by default on Debian/bookworm (and apparently Arch). These are the steps I took:
https://wiki.archlinux.org/title/Dell_XPS_17_(9720)#Microphone
I recently did that again. I had also done it a couple of months ago, when I thought the crashiness was resolved, then it seemed to come back.
I don't think the ALSA settings have any bearing on suspend-resume
What's more worrying is that the DMIC1 setting used for rt714 is NOT the default in UCM. I'll add a new issue for this.
Going back to the sequence, the first log shows the sequence is clearly problematic
static int __maybe_unused intel_suspend(struct device *dev)
{
struct sdw_cdns *cdns = dev_get_drvdata(dev);
struct sdw_intel *sdw = cdns_to_intel(cdns);
struct sdw_bus *bus = &cdns->bus;
u32 clock_stop_quirks;
int ret;
if (bus->prop.hw_disabled || !sdw->startup_done) {
dev_dbg(dev, "SoundWire master %d is disabled or not-started, ignoring\n",
bus->link_id);
return 0;
}
if (pm_runtime_suspended(dev)) {
dev_dbg(dev, "pm_runtime status: suspended\n");
clock_stop_quirks = sdw->link_res->clock_stop_quirks;
if ((clock_stop_quirks & SDW_INTEL_CLK_STOP_BUS_RESET) ||
!clock_stop_quirks) {
if (pm_runtime_suspended(dev->parent)) {
/*
* paranoia check: this should not happen with the .prepare
* resume to full power
*/
dev_err(dev, "%s: invalid config: parent is suspended\n", __func__);
} else {
sdw_intel_shim_wake(sdw, false);
}
}
return 0;
}
Only the paranoid survive, eh?
wait, i think we fixed this already.
@eighthave can you please double-check if this patch is in your kernel?
6f4867fa5760 soundwire: intel_auxdevice: use pm_runtime_resume() instead of pm_request_resume()
It's queued for 6.10, and it would prevent the race condition that seems to happen according to your log. pm_request_resume was an async resume, and with the time it takes to resume the parent, if you don't wait until the end of the resume then the children may encounter an invalid config.
I'm on Debian's kernel 6.7.12+bpo-amd64. Debian mostly sticks to plain upstream kernels, so there aren't usually these kinds of patches added to it. I'll check in git to see if that commit is included in 6.7.12
Looks like that patch is only in 6.10.x: https://github.com/search?q=repo%3Atorvalds%2Flinux+soundwire%3A+intel_auxdevice%3A+use+pm_runtime_resume%28%29+instead+of+pm_request_resume%28%29&type=commits
this is a kernel issue, moving.
@ujfalusi can this be closed ? i.e. does https://github.com/thesofproject/linux/commit/6f4867fa57604fc898a63ee73fe890786b9f4a72 fix issue and is available for older kernels ?
@lgirdwood, I'm not sure. https://github.com/thesofproject/linux/commit/6f4867fa57604fc898a63ee73fe890786b9f4a72 do fix something, but even if that patch is in kernel, the runtime PM gets very confused and in a similar way: https://github.com/thesofproject/linux/issues/5212
Something is not adding up. I cannot see the point where and how it happens.
Describe the bug
After a couple of days of running without reboot, the audio will stop working. It outputs what looks like a crash log to dmesg (I'm not a kernel dev, but I am a C/Python/Java/Debian Developer). To reset it, I have tried
rmmod snd_sof_pci_intel_tgl; modprobe snd_sof_pci_intel_tgl
but that doesn't seem to work. Rebooting always does.To Reproduce
Keep using the laptop normally for work, usually sometime around Wednesday, the audio stops working. There is always error messages from sof-audio-pci-intel-tgl in dmesg.
Reproduction Rate
It happens every time after a couple of days.
Expected behavior
The audio to continue working and not crash.
Impact
After the crash, audio is totally non-functional. Apps that use the audio will sometimes hang.
Environment 1) Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
Platform: Debian/bookworm on amd64.
Screenshots or console output
Longer log: dmesg.txt