Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] audio crashes and stops working until reboot (Dell 9720 w/ Alder Lake PCH-P audio) #5213

Open
eighthave opened this issue Jun 14, 2023 · 50 comments
Labels
bug Something isn't working SDW Applies to SoundWire bus for codec connection

Comments

@eighthave
Copy link

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).
  2. Name of the topology file
    • Topology: {FILE}
  3. Name of the platform(s) on which the bug is observed.
    • Platform: Debian/bookworm on amd64.

Screenshots or console output

[360057.708434] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_power_up: timeout on HDA_DSP_REG_ADSPCS read
[360057.708455] sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp core power up failed: core_mask 1
[360057.708464] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to enable target core for widget PIPELINE.3.ALH258.OUT
[360057.708472] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
[360057.708484] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 2 dir 0
[360057.708493] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[360057.708563]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[360057.708593] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[360057.708612]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[360057.708685] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[360061.544391] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_power_up: timeout on HDA_DSP_REG_ADSPCS read
[360061.544419] sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp core power up failed: core_mask 1
[360061.544430] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to enable target core for widget PIPELINE.3.ALH258.OUT
[360061.544438] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
[360061.544449] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 2 dir 0
[360061.544458] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[360061.544504]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[360061.544536] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[360061.544552]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[360061.544614] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[360542.393428] EXT4-fs (mmcblk0p1): unmounting filesystem 010cd8fc-59ca-41ff-bdb7-73ee1adf6bac.
[360542.478689]  mmcblk0: p1
[360551.677104] mmc0: card 0001 removed
[360551.854962] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_power_up: timeout on HDA_DSP_REG_ADSPCS read
[360551.854990] sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp core power up failed: core_mask 1
[360551.855001] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to enable target core for widget PIPELINE.3.ALH258.OUT
[360551.855010] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
[360551.855024] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 2 dir 0
[360551.855036] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[360551.855121]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[360551.855155] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[360551.855178]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[360551.855242] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[360551.914958] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_power_up: timeout on HDA_DSP_REG_ADSPCS read
[360551.914985] sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp core power up failed: core_mask 1
[360551.914993] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to enable target core for widget PIPELINE.3.ALH258.OUT
[360551.915002] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
[360551.915011] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 2 dir 0
[360551.915019] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[360551.915086]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[360551.915113] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[360551.915130]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[360551.915189] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[360554.145152] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[360557.812741] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[360557.823584] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[360559.044605] PM: suspend entry (s2idle)
[360559.049466] Filesystems sync: 0.004 seconds
[360559.050142] (NULL device *): firmware: direct-loading firmware regulatory.db.p7s
[360559.050185] (NULL device *): firmware: direct-loading firmware iwlwifi-so-a0-gf-a0.pnvm
[360559.050261] (NULL device *): firmware: direct-loading firmware regulatory.db
[360559.050474] (NULL device *): firmware: direct-loading firmware i915/adlp_dmc.bin
[360559.050486] (NULL device *): firmware: direct-loading firmware intel/ibt-0040-0041.ddc
[360559.050703] (NULL device *): firmware: direct-loading firmware intel/sof-tplg/sof-adl-rt711-l0-rt1316-l12-rt714-l3.tplg
[360559.051109] (NULL device *): firmware: direct-loading firmware i915/adlp_guc_70.bin
[360559.051474] (NULL device *): firmware: direct-loading firmware i915/tgl_huc.bin
[360559.052303] (NULL device *): firmware: direct-loading firmware intel/ibt-0040-0041.sfi
[360559.053473] (NULL device *): firmware: direct-loading firmware iwlwifi-so-a0-gf-a0-74.ucode
[360559.087291] Freezing user space processes
[360559.092550] Freezing user space processes completed (elapsed 0.005 seconds)
[360559.092565] OOM killer disabled.
[360559.092568] Freezing remaining freezable tasks
[360559.094635] Freezing remaining freezable tasks completed (elapsed 0.002 seconds)
[360559.094648] printk: Suspending console(s) (use no_console_suspend to debug)
[360559.137735] soundwire_intel soundwire_intel.link.2: intel_link_power_down: Unbalanced power-up/down calls
[360559.137814] soundwire_intel soundwire_intel.link.1: intel_link_power_down: Unbalanced power-up/down calls
[360559.190396] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda_dsp_core_reset_enter: timeout on HDA_DSP_REG_ADSPCS read
[360559.190407] sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp core reset failed: core_mask 1
[360559.190411] sof-audio-pci-intel-tgl 0000:00:1f.3: failed to power down DSP during suspend
[360559.190414] sof-audio-pci-intel-tgl 0000:00:1f.3: error: suspending dsp
[360559.190417] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to power down DSP during suspend -110
[360559.190422] sof-audio-pci-intel-tgl 0000:00:1f.3: PM: pci_pm_suspend(): snd_sof_suspend+0x0/0x20 [snd_sof] returns -110
[360559.190477] sof-audio-pci-intel-tgl 0000:00:1f.3: PM: dpm_run_callback(): pci_pm_suspend+0x0/0x170 returns -110
[360559.190493] sof-audio-pci-intel-tgl 0000:00:1f.3: PM: failed to suspend async: error -110
[360560.168721] PM: Some devices failed to suspend, or early wake event detected
[360560.187156] nvme nvme0: 16/0/0 default/read/poll queues
[360560.240719] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
[360560.240737] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
[360560.240744] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[360560.240773] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
[360560.241985] soundwire_intel soundwire_intel.link.1: Failed to power up link: -11
[360560.241991] soundwire_intel soundwire_intel.link.1: intel_resume failed: -11
[360560.241995] soundwire_intel soundwire_intel.link.1: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[360560.242010] soundwire_intel soundwire_intel.link.1: PM: failed to resume: error -11
[360560.508183] usb 1-3.2.3-port1: cannot disable (err = -71)
[360560.518064] usb 1-3.2.1: reset high-speed USB device number 41 using xhci_hcd
[360560.530057] hub 1-3.2.3:1.0: hub_ext_port_status failed (err = -71)
[360560.530395] usb 1-3.2.3-port3: cannot disable (err = -71)
[360560.761532] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 3 device 4 addr 2232 len 1
[360560.761560] soundwire sdw-master-1: trf on Slave 4 failed:-110 write addr 2232 count 0
[360560.761574] rt1316-sdca sdw:1:025d:1316:01: Unable to sync register 0x2232. -110
[360560.762718] soundwire_intel soundwire_intel.link.2: Failed to power up link: -11
[360560.762725] soundwire_intel soundwire_intel.link.2: intel_resume failed: -11
[360560.762730] soundwire_intel soundwire_intel.link.2: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[360560.762759] soundwire_intel soundwire_intel.link.2: PM: failed to resume: error -11
[360561.273557] soundwire_intel soundwire_intel.link.2: IO transfer timed out, cmd 3 device 6 addr 2232 len 1
[360561.273584] soundwire sdw-master-2: trf on Slave 6 failed:-110 write addr 2232 count 0
[360561.273599] rt1316-sdca sdw:2:025d:1316:01: Unable to sync register 0x2232. -110
[360561.274747] soundwire_intel soundwire_intel.link.3: Failed to power up link: -11
[360561.274753] soundwire_intel soundwire_intel.link.3: intel_resume failed: -11
[360561.274758] soundwire_intel soundwire_intel.link.3: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[360561.274788] soundwire_intel soundwire_intel.link.3: PM: failed to resume: error -11
[360561.279861] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
[360561.280511] mei_pxp 0000:00:16.0-fbf6fcf1-96cf-4e2e-a6a6-1bab8cbe36b1: bound 0000:00:02.0 (ops i915_pxp_tee_component_ops [i915])
[360561.280915] OOM killer enabled.
[360561.280916] Restarting tasks ... 
[360561.281096] hub 1-3.2.3:1.0: hub_ext_port_status failed (err = -71)
[360561.281218] hub 1-3.2.3:1.0: hub_ext_port_status failed (err = -71)
[360561.281595] usb 1-3.2.1: USB disconnect, device number 41
[360561.283296] done.
[360561.283303] random: crng reseeded on system resumption
[360561.329533] thermal thermal_zone10: failed to read out thermal zone (-61)
[360561.352492] PM: suspend exit
[360561.352527] PM: suspend entry (s2idle)
[360561.354921] Filesystems sync: 0.002 seconds
[360561.398091] Freezing user space processes
[360561.529601] usb 1-3.2.1: new high-speed USB device number 42 using xhci_hcd
[360561.657330] usb 1-3.2.1: New USB device found, idVendor=18d1, idProduct=4ee7, bcdDevice=99.99
[360561.657345] usb 1-3.2.1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[360561.657351] usb 1-3.2.1: Product: Nexus 7
[360561.657355] usb 1-3.2.1: Manufacturer: asus
[360561.657358] usb 1-3.2.1: SerialNumber: fffffffffffffffffffffffffff
[360561.757291] usb 1-3.2.1: USB disconnect, device number 42
[360561.842885] Freezing user space processes completed (elapsed 0.444 seconds)
[360561.842916] OOM killer disabled.
[360561.842922] Freezing remaining freezable tasks
[360561.997631] usb 1-3.2.1: new high-speed USB device number 43 using xhci_hcd
[360562.122766] usb 1-3.2.1: New USB device found, idVendor=18d1, idProduct=4ee7, bcdDevice=99.99
[360562.122788] usb 1-3.2.1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[360562.122795] usb 1-3.2.1: Product: Nexus 7
[360562.122799] usb 1-3.2.1: Manufacturer: asus
[360562.122803] usb 1-3.2.1: SerialNumber: fffffffffffffffffffffffffff
[360562.127057] Freezing remaining freezable tasks completed (elapsed 0.284 seconds)
[360562.127082] printk: Suspending console(s) (use no_console_suspend to debug)
[360562.168781] soundwire_intel soundwire_intel.link.3: intel_link_power_down: Unbalanced power-up/down calls
[360562.168905] soundwire_intel soundwire_intel.link.2: intel_link_power_down: Unbalanced power-up/down calls
[360562.169031] soundwire_intel soundwire_intel.link.1: intel_link_power_down: Unbalanced power-up/down calls
[360562.169133] soundwire_intel soundwire_intel.link.0: intel_link_power_down: Unbalanced power-up/down calls
[360562.190011] usb 1-3.2.3-port1: device 1-3.2.3.1 not suspended yet
[360562.190024] usb 1-3.2.3-port3: device 1-3.2.3.3 not suspended yet
[360562.640862] ACPI: EC: interrupt blocked
[390765.574520] ACPI: EC: interrupt unblocked
[390765.772410] i915 0000:00:02.0: [drm] GT0: GuC firmware i915/adlp_guc_70.bin version 70.5.1
[390765.772415] i915 0000:00:02.0: [drm] GT0: HuC firmware i915/tgl_huc.bin version 7.9.3
[390765.780784] nvme nvme0: 16/0/0 default/read/poll queues
[390765.786897] i915 0000:00:02.0: [drm] HuC authenticated
[390765.787493] i915 0000:00:02.0: [drm] GT0: GUC: submission enabled
[390765.787495] i915 0000:00:02.0: [drm] GT0: GUC: SLPC enabled
[390765.788048] i915 0000:00:02.0: [drm] GuC RC: enabled
[390766.262916] ------------[ cut here ]------------
[390766.262927] Unbalanced IRQ 201 wake disable
[390766.262942] WARNING: CPU: 2 PID: 169960 at kernel/irq/manage.c:910 irq_set_irq_wake+0x155/0x1a0
[390766.262964] Modules linked in: mmc_block tls sd_mod sr_mod cdrom sg uas usb_storage scsi_mod r8153_ecm scsi_common usbhid cdc_mbim cdc_wdm cdc_ncm cdc_ether usbnet r8152 mii ctr ccm rfcomm cmac algif_hash algif_skcipher af_alg wireguard libchacha20poly1305 chacha_x86_64 poly1305_x86_64 curve25519_x86_64 libcurve25519_generic libchacha ip6_udp_tunnel udp_tunnel snd_seq_dummy snd_hrtimer snd_seq snd_seq_device overlay qrtr bnep binfmt_misc nls_ascii nls_cp437 vfat fat snd_ctl_led snd_soc_sof_sdw snd_soc_intel_hda_dsp_common snd_sof_probes snd_soc_intel_sof_maxim_common snd_soc_rt711_sdca snd_soc_rt715_sdca snd_soc_rt1316_sdw regmap_sdw_mbq snd_hda_codec_hdmi regmap_sdw snd_soc_dmic snd_sof_pci_intel_tgl snd_sof_intel_hda_common soundwire_intel soundwire_generic_allocation soundwire_cadence snd_sof_intel_hda snd_sof_pci snd_sof_xtensa_dsp snd_sof iwlmvm snd_sof_utils snd_soc_hdac_hda snd_hda_ext_core snd_soc_acpi_intel_match snd_soc_acpi mac80211 snd_soc_core libarc4 snd_compress soundwire_bus iwlwifi snd_hda_intel
[390766.263139]  x86_pkg_temp_thermal snd_intel_dspcfg intel_powerclamp snd_intel_sdw_acpi btusb coretemp snd_hda_codec btrtl btbcm kvm_intel btintel snd_hda_core btmtk bluetooth cfg80211 snd_hwdep uvcvideo processor_thermal_device_pci kvm hid_sensor_als snd_pcm videobuf2_vmalloc jitterentropy_rng processor_thermal_device hid_sensor_trigger dell_laptop dell_wmi uvc mei_hdcp mei_pxp snd_timer processor_thermal_rfim iTCO_wdt irqbypass hid_sensor_iio_common drbg dell_smbios videobuf2_memops intel_rapl_msr rapl videobuf2_v4l2 joydev intel_cstate ledtrig_audio ansi_cprng dell_wmi_sysman dcdbas ecdh_generic videodev intel_uncore ucsi_acpi typec_ucsi industrialio_triggered_buffer processor_thermal_mbox dell_wmi_ddv dell_wmi_descriptor firmware_attributes_class wmi_bmof snd intel_pmc_bxt pcspkr mei_me videobuf2_common roles kfifo_buf processor_thermal_rapl iTCO_vendor_support mc watchdog ecc mei soundcore rfkill industrialio intel_rapl_common typec igen6_edac int3403_thermal int340x_thermal_zone intel_hid int3400_thermal
[390766.263301]  intel_pmc_core acpi_pad sparse_keymap acpi_thermal_rel acpi_tad hid_multitouch ac evdev serio_raw nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse msr loop configfs efi_pstore 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 crc32_pclmul i2c_algo_bit crc32c_intel nvme drm_display_helper nvme_core ghash_clmulni_intel hid_generic cec sha512_ssse3 xhci_pci t10_pi xhci_hcd rc_core sha512_generic crc64_rocksoft_generic ttm crc64_rocksoft crc_t10dif rtsx_pci_sdmmc usbcore drm_kms_helper crct10dif_generic intel_lpss_pci mmc_core i2c_hid_acpi aesni_intel crct10dif_pclmul video i2c_i801 intel_ish_ipc i2c_hid intel_lpss crc64 drm thunderbolt crypto_simd cryptd rtsx_pci intel_ishtp i2c_smbus psmouse idma64 usb_common crct10dif_common hid battery wmi button
[390766.263527] CPU: 2 PID: 169960 Comm: kworker/u32:100 Not tainted 6.3.0-0-amd64 thesofproject/sof#1  Debian 6.3.5-1~exp1
[390766.263536] Hardware name: Dell Inc. XPS 17 9720/FFFFFF, BIOS 1.16.1 03/22/2023
[390766.263541] Workqueue: events_unbound async_run_entry_fn
[390766.263556] RIP: 0010:irq_set_irq_wake+0x155/0x1a0
[390766.263567] 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 98 da 27 ab e8 eb a2 f6 ff <0f> 0b 31 ed e9 20 ff ff ff 48 8b 43 38 31 ed 81 08 00 40 00 00 e9
[390766.263575] RSP: 0018:ffffc2fa87ebbd58 EFLAGS: 00010086
[390766.263583] RAX: 0000000000000000 RBX: ffff9ea20028da00 RCX: 0000000000000000
[390766.263588] RDX: 0000000000000003 RSI: ffffffffab236b9a RDI: 00000000ffffffff
[390766.263592] RBP: 00000000ffffffea R08: ffffffffab861fa0 R09: 0000000000ffff0a
[390766.263597] R10: 0000000000000002 R11: ffffffffab8cd2f0 R12: 00000000000000c9
[390766.263602] R13: 0000000000000000 R14: ffff9e9ec573a1d0 R15: ffff9e9f01f241a8
[390766.263607] FS:  0000000000000000(0000) GS:ffff9ea23f480000(0000) knlGS:0000000000000000
[390766.263613] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[390766.263618] CR2: 00005589113cccc0 CR3: 000000043fc20000 CR4: 0000000000f50ee0
[390766.263624] PKRU: 55555554
[390766.263627] Call Trace:
[390766.263633]  <TASK>
[390766.263637]  ? irq_set_irq_wake+0x155/0x1a0
[390766.263646]  ? __warn+0x81/0x130
[390766.263662]  ? irq_set_irq_wake+0x155/0x1a0
[390766.263671]  ? report_bug+0x191/0x1c0
[390766.263686]  ? _raw_spin_lock_irqsave+0x27/0x60
[390766.263701]  ? handle_bug+0x41/0x70
[390766.263712]  ? exc_invalid_op+0x17/0x70
[390766.263722]  ? asm_exc_invalid_op+0x1a/0x20
[390766.263736]  ? irq_set_irq_wake+0x155/0x1a0
[390766.263746]  ? irq_set_irq_wake+0x155/0x1a0
[390766.263757]  hda_dsp_resume+0xdf/0x1d0 [snd_sof_intel_hda_common]
[390766.263813]  ? __pfx_pci_pm_resume+0x10/0x10
[390766.263829]  sof_resume.isra.0+0x6b/0x270 [snd_sof]
[390766.263907]  ? __pfx_pci_pm_resume+0x10/0x10
[390766.263919]  dpm_run_callback+0x89/0x1e0
[390766.263933]  device_resume+0x88/0x190
[390766.263943]  async_resume+0x1e/0x60
[390766.263953]  async_run_entry_fn+0x31/0x130
[390766.263967]  process_one_work+0x1c5/0x3c0
[390766.263977]  worker_thread+0x51/0x390
[390766.263985]  ? __pfx_worker_thread+0x10/0x10
[390766.263991]  kthread+0xea/0x120
[390766.264001]  ? __pfx_kthread+0x10/0x10
[390766.264011]  ret_from_fork+0x29/0x50
[390766.264030]  </TASK>
[390766.264033] ---[ end trace 0000000000000000 ]---
[390766.265215] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
[390766.265226] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
[390766.265230] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[390766.265247] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
[390766.266326] soundwire_intel soundwire_intel.link.1: Failed to power up link: -11
[390766.266329] soundwire_intel soundwire_intel.link.1: intel_resume failed: -11
[390766.266331] soundwire_intel soundwire_intel.link.1: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[390766.266339] soundwire_intel soundwire_intel.link.1: PM: failed to resume: error -11
[390766.424089] usb 1-3.2.3: reset high-speed USB device number 27 using xhci_hcd
[390766.767593] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 3 device 4 addr 2232 len 1
[390766.767623] soundwire sdw-master-1: trf on Slave 4 failed:-110 write addr 2232 count 0
[390766.767639] rt1316-sdca sdw:1:025d:1316:01: Unable to sync register 0x2232. -110
[390766.768806] soundwire_intel soundwire_intel.link.2: Failed to power up link: -11
[390766.768814] soundwire_intel soundwire_intel.link.2: intel_resume failed: -11
[390766.768822] soundwire_intel soundwire_intel.link.2: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[390766.768857] soundwire_intel soundwire_intel.link.2: PM: failed to resume: error -11
[390767.279553] soundwire_intel soundwire_intel.link.2: IO transfer timed out, cmd 3 device 6 addr 2232 len 1
[390767.279580] soundwire sdw-master-2: trf on Slave 6 failed:-110 write addr 2232 count 0
[390767.279594] rt1316-sdca sdw:2:025d:1316:01: Unable to sync register 0x2232. -110
[390767.280764] soundwire_intel soundwire_intel.link.3: Failed to power up link: -11
[390767.280772] soundwire_intel soundwire_intel.link.3: intel_resume failed: -11
[390767.280779] soundwire_intel soundwire_intel.link.3: PM: dpm_run_callback(): pm_generic_resume+0x0/0x40 returns -11
[390767.280811] soundwire_intel soundwire_intel.link.3: PM: failed to resume: error -11
[390768.079582] ucsi_acpi USBC000:00: failed to re-enable notifications (-110)
[390769.105264] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
[390769.105968] mei_pxp 0000:00:16.0-fbf6fcf1-96cf-4e2e-a6a6-1bab8cbe36b1: bound 0000:00:02.0 (ops i915_pxp_tee_component_ops [i915])
[390769.106215] OOM killer enabled.
[390769.106221] Restarting tasks ... 
[390769.107566] usb 1-3.2.3.1: USB disconnect, device number 38
[390769.113946] usb 1-3.2.1: USB disconnect, device number 43
[390769.114135] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: MCP_CONTROL_SW_RST is not cleared
[390769.114142] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: MCP_CONTROL_CLK_STOP_CLR is not cleared
[390769.114144] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: MCP_CONTROL_HW_RST is not cleared
[390769.114987] done.
[390769.114996] random: crng reseeded on system resumption
[390769.146828] thermal thermal_zone10: failed to read out thermal zone (-61)
[390769.166085] PM: suspend exit
[390769.339291] usb 1-3.2.3.1: new high-speed USB device number 44 using xhci_hcd
[390769.459911] usb 1-3.2.3.1: New USB device found, idVendor=2e04, idProduct=c001, bcdDevice=ff.ff
[390769.459916] usb 1-3.2.3.1: New USB device strings: Mfr=3, Product=4, SerialNumber=5
[390769.459917] usb 1-3.2.3.1: Product: Nokia 3.1
[390769.459918] usb 1-3.2.3.1: Manufacturer: MediaTek
[390769.459918] usb 1-3.2.3.1: SerialNumber: FFFFFFFFFFFFFFFFFFFFFF
[390769.463317] usb-storage 1-3.2.3.1:1.0: USB Mass Storage device detected
[390769.463466] scsi host0: usb-storage 1-3.2.3.1:1.0
[390769.465106] r8152-cfgselector 1-3.2.3.3: USB disconnect, device number 39
[390769.615278] soundwire_intel soundwire_intel.link.3: IO transfer timed out, cmd 3 device 7 addr 45 len 1
[390769.615302] soundwire sdw-master-3: trf on Slave 7 failed:-110 write addr 45 count 0
[390769.615305] rt715-sdca sdw:3:025d:0714:01: SDW_SCP_SYSTEMCTRL write failed:-110
[390769.615307] rt715-sdca sdw:3:025d:0714:01: clock stop prepare failed:-110
[390769.615308] soundwire_intel soundwire_intel.link.3: prepare clock stop failed -110
[390769.615310] soundwire_intel soundwire_intel.link.3: intel_stop_bus: cannot stop clock: -110
[390769.615312] soundwire_intel soundwire_intel.link.3: intel_link_power_down: Unbalanced power-up/down calls
[390769.643283] usb 1-3.2.3.3: new high-speed USB device number 45 using xhci_hcd
[390769.651275] soundwire_intel soundwire_intel.link.0: IO transfer timed out, cmd 3 device 5 addr 45 len 1
[390769.651298] soundwire sdw-master-0: trf on Slave 5 failed:-110 write addr 45 count 0
[390769.651301] rt711-sdca sdw:0:025d:0711:01: SDW_SCP_SYSTEMCTRL write failed:-110
[390769.651303] rt711-sdca sdw:0:025d:0711:01: clock stop prepare failed:-110
[390769.651305] soundwire_intel soundwire_intel.link.0: prepare clock stop failed -110
[390769.651306] soundwire_intel soundwire_intel.link.0: intel_stop_bus: cannot stop clock: -110
[390769.651309] soundwire_intel soundwire_intel.link.0: intel_link_power_down: Unbalanced power-up/down calls
[390769.756730] usb 1-3.2.3.3: New USB device found, idVendor=0bda, idProduct=8153, bcdDevice=30.00
[390769.756734] usb 1-3.2.3.3: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[390769.756735] usb 1-3.2.3.3: Product: USB 10/100/1000 LAN
[390769.756736] usb 1-3.2.3.3: Manufacturer: Realtek
[390769.756736] usb 1-3.2.3.3: SerialNumber: 000001000000
[390769.859534] r8152-cfgselector 1-3.2.3.3: reset high-speed USB device number 45 using xhci_hcd
[390770.003227] r8152 1-3.2.3.3:1.0: load rtl8153a-3 v2 02/07/20 successfully
[390770.032025] r8152 1-3.2.3.3:1.0 eth0: v1.12.13
[390770.504391] scsi 0:0:0:0: CD-ROM            Linux    File-CD Gadget   0318 PQ: 0 ANSI: 2
[390770.504778] sr 0:0:0:0: Power-on or device reset occurred
[390770.505337] sr 0:0:0:0: [sr0] scsi-1 drive
[390770.505835] sr 0:0:0:0: Attached scsi CD-ROM sr0
[390770.505917] sr 0:0:0:0: Attached scsi generic sg0 type 5
[390771.135241] r8152 1-3.2.3.3:1.0 enx9cebe81f373d: renamed from eth0
[390773.199467] ucsi_acpi USBC000:00: failed to re-enable notifications (-110)
[390773.701338] IPv6: ADDRCONF(NETDEV_CHANGE): enx9cebe81f373d: link becomes ready
[390773.702491] r8152 1-3.2.3.3:1.0 enx9cebe81f373d: carrier on
[390774.463319] usb 1-3.2.1: new high-speed USB device number 46 using xhci_hcd
[390774.592646] usb 1-3.2.1: New USB device found, idVendor=18d1, idProduct=4ee7, bcdDevice=99.99
[390774.592662] usb 1-3.2.1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[390774.592668] usb 1-3.2.1: Product: Nexus 7
[390774.592671] usb 1-3.2.1: Manufacturer: asus
[390774.592674] usb 1-3.2.1: SerialNumber: fffffffffffffffffff
[390774.979734] usb 1-3.2.1: USB disconnect, device number 46
[390775.235273] usb 1-3.2.1: new high-speed USB device number 47 using xhci_hcd
[390775.364587] usb 1-3.2.1: New USB device found, idVendor=18d1, idProduct=4ee7, bcdDevice=99.99
[390775.364607] usb 1-3.2.1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[390775.364613] usb 1-3.2.1: Product: Nexus 7
[390775.364617] usb 1-3.2.1: Manufacturer: asus
[390775.364621] usb 1-3.2.1: SerialNumber: fffffffffffffffffff
[391262.086037] sof-audio-pci-intel-tgl 0000:00:1f.3: timeout waiting for stream reset
[391262.086043] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hdac prepare failed: -110
[391262.086045] sof-audio-pci-intel-tgl 0000:00:1f.3: platform hw params failed
[391262.086045] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[391262.086061]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[391262.086065] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[391262.086068]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[391262.086382] sof-audio-pci-intel-tgl 0000:00:1f.3: timeout waiting for stream reset
[391262.086383] sof-audio-pci-intel-tgl 0000:00:1f.3: error: platform hw free failed
[391262.086385] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -110
[391262.086388] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[391262.094053] sof-audio-pci-intel-tgl 0000:00:1f.3: timeout waiting for stream reset
[391262.094057] sof-audio-pci-intel-tgl 0000:00:1f.3: error: hdac prepare failed: -110
[391262.094059] sof-audio-pci-intel-tgl 0000:00:1f.3: platform hw params failed
[391262.094060] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -110
[391262.094068]  Speaker: ASoC: error at __soc_pcm_hw_params on Speaker: -110
[391262.094072] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[391262.094074]  Speaker: ASoC: error at dpcm_fe_dai_hw_params on Speaker: -110
[391262.094396] sof-audio-pci-intel-tgl 0000:00:1f.3: timeout waiting for stream reset
[391262.094398] sof-audio-pci-intel-tgl 0000:00:1f.3: error: platform hw free failed
[391262.094400] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -110
[391262.094405] sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 6
[391281.299442] Disabling lock debugging due to kernel taint
[391281.448454] ------------[ cut here ]------------
[391281.448457] remove_proc_entry: removing non-empty directory 'irq/201', leaking at least 'AudioDSP'
[391281.448463] WARNING: CPU: 2 PID: 171955 at fs/proc/generic.c:718 remove_proc_entry+0x19c/0x1c0
[391281.448468] Modules linked in: mmc_block tls sd_mod sr_mod cdrom sg uas usb_storage scsi_mod r8153_ecm scsi_common usbhid cdc_mbim cdc_wdm cdc_ncm cdc_ether usbnet r8152 mii ctr ccm rfcomm cmac algif_hash algif_skcipher af_alg wireguard libchacha20poly1305 chacha_x86_64 poly1305_x86_64 curve25519_x86_64 libcurve25519_generic libchacha ip6_udp_tunnel udp_tunnel snd_seq_dummy snd_hrtimer snd_seq snd_seq_device overlay qrtr bnep binfmt_misc nls_ascii nls_cp437 vfat fat snd_ctl_led snd_soc_sof_sdw snd_soc_intel_hda_dsp_common snd_sof_probes snd_soc_intel_sof_maxim_common snd_soc_rt711_sdca snd_soc_rt715_sdca snd_soc_rt1316_sdw regmap_sdw_mbq snd_hda_codec_hdmi regmap_sdw snd_soc_dmic snd_sof_pci_intel_tgl(-) snd_sof_intel_hda_common soundwire_intel soundwire_generic_allocation soundwire_cadence snd_sof_intel_hda snd_sof_pci snd_sof_xtensa_dsp snd_sof iwlmvm snd_sof_utils snd_soc_hdac_hda snd_hda_ext_core snd_soc_acpi_intel_match snd_soc_acpi mac80211 snd_soc_core libarc4 snd_compress soundwire_bus iwlwifi snd_hda_intel
[391281.448501]  x86_pkg_temp_thermal snd_intel_dspcfg intel_powerclamp snd_intel_sdw_acpi btusb coretemp snd_hda_codec btrtl btbcm kvm_intel btintel snd_hda_core btmtk bluetooth cfg80211 snd_hwdep uvcvideo processor_thermal_device_pci kvm hid_sensor_als snd_pcm videobuf2_vmalloc jitterentropy_rng processor_thermal_device hid_sensor_trigger dell_laptop dell_wmi uvc mei_hdcp mei_pxp snd_timer processor_thermal_rfim iTCO_wdt irqbypass hid_sensor_iio_common drbg dell_smbios videobuf2_memops intel_rapl_msr rapl videobuf2_v4l2 joydev intel_cstate ledtrig_audio ansi_cprng dell_wmi_sysman dcdbas ecdh_generic videodev intel_uncore ucsi_acpi typec_ucsi industrialio_triggered_buffer processor_thermal_mbox dell_wmi_ddv dell_wmi_descriptor firmware_attributes_class wmi_bmof snd intel_pmc_bxt pcspkr mei_me videobuf2_common roles kfifo_buf processor_thermal_rapl iTCO_vendor_support mc watchdog ecc mei soundcore rfkill industrialio intel_rapl_common typec igen6_edac int3403_thermal int340x_thermal_zone intel_hid int3400_thermal
[391281.448530]  intel_pmc_core acpi_pad sparse_keymap acpi_thermal_rel acpi_tad hid_multitouch ac evdev serio_raw nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse msr loop configfs efi_pstore 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 crc32_pclmul i2c_algo_bit crc32c_intel nvme drm_display_helper nvme_core ghash_clmulni_intel hid_generic cec sha512_ssse3 xhci_pci t10_pi xhci_hcd rc_core sha512_generic crc64_rocksoft_generic ttm crc64_rocksoft crc_t10dif rtsx_pci_sdmmc usbcore drm_kms_helper crct10dif_generic intel_lpss_pci mmc_core i2c_hid_acpi aesni_intel crct10dif_pclmul video i2c_i801 intel_ish_ipc i2c_hid intel_lpss crc64 drm thunderbolt crypto_simd cryptd rtsx_pci intel_ishtp i2c_smbus psmouse idma64 usb_common crct10dif_common hid battery wmi button
[391281.448569] CPU: 2 PID: 171955 Comm: rmmod Tainted: G  R     W          6.3.0-0-amd64 thesofproject/sof#1  Debian 6.3.5-1~exp1
[391281.448571] Hardware name: Dell Inc. XPS 17 9720/FFFFFF, BIOS 1.16.1 03/22/2023
[391281.448572] RIP: 0010:remove_proc_entry+0x19c/0x1c0
[391281.448574] Code: c7 08 a3 29 ab 48 85 c0 48 8d 90 78 ff ff ff 48 0f 45 c2 48 8b 53 f0 4c 8b 80 a0 00 00 00 48 8b 92 a0 00 00 00 e8 04 74 c3 ff <0f> 0b e9 76 ff ff ff 48 8b 73 18 48 c7 c7 e0 a2 29 ab e8 ed 73 c3
[391281.448575] RSP: 0018:ffffc2fa89e93c10 EFLAGS: 00010286
[391281.448576] RAX: 0000000000000000 RBX: ffff9e9f01979288 RCX: 0000000000000000
[391281.448577] RDX: 0000000000000002 RSI: ffffffffab236b9a RDI: 00000000ffffffff
[391281.448578] RBP: ffff9e9f01979200 R08: 0000000000000000 R09: ffffc2fa89e93aa0
[391281.448579] R10: 0000000000000003 R11: ffffffffab8ce238 R12: ffff9e9f01979280
[391281.448579] R13: ffffc2fa89e93c66 R14: ffffc2fa89e93c66 R15: ffff9e9ec0a2c240
[391281.448580] FS:  00007f8b03922040(0000) GS:ffff9ea23f480000(0000) knlGS:0000000000000000
[391281.448581] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[391281.448582] CR2: 0000561e2eb292f8 CR3: 0000000145cd2000 CR4: 0000000000f50ee0
[391281.448582] PKRU: 55555554
[391281.448583] Call Trace:
[391281.448585]  <TASK>
[391281.448585]  ? remove_proc_entry+0x19c/0x1c0
[391281.448587]  ? __warn+0x81/0x130
[391281.448591]  ? remove_proc_entry+0x19c/0x1c0
[391281.448592]  ? report_bug+0x191/0x1c0
[391281.448596]  ? prb_read_valid+0x1b/0x30
[391281.448598]  ? handle_bug+0x41/0x70
[391281.448601]  ? exc_invalid_op+0x17/0x70
[391281.448602]  ? asm_exc_invalid_op+0x1a/0x20
[391281.448605]  ? remove_proc_entry+0x19c/0x1c0
[391281.448607]  unregister_irq_proc+0xf4/0x120
[391281.448609]  free_desc+0x29/0x70
[391281.448610]  irq_free_descs+0x4f/0x80
[391281.448611]  msi_domain_free_locked.part.0+0x191/0x1c0
[391281.448614]  msi_domain_free_irqs_all_locked+0x6e/0x90
[391281.448615]  pci_free_msi_irqs+0x12/0x40
[391281.448618]  pci_free_irq_vectors+0x51/0x60
[391281.448619]  release_nodes+0x3d/0xb0
[391281.448622]  devres_release_all+0x8c/0xc0
[391281.448624]  device_unbind_cleanup+0xe/0x70
[391281.448626]  device_release_driver_internal+0x1cc/0x200
[391281.448628]  driver_detach+0x48/0x90
[391281.448629]  bus_remove_driver+0x6d/0xf0
[391281.448630]  pci_unregister_driver+0x2e/0xb0
[391281.448633]  __do_sys_delete_module+0x1d2/0x320
[391281.448635]  do_syscall_64+0x5c/0xc0
[391281.448637]  ? fpregs_assert_state_consistent+0x26/0x50
[391281.448639]  ? exit_to_user_mode_prepare+0x40/0x1d0
[391281.448641]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[391281.448642] RIP: 0033:0x7f8b03328847
[391281.448644] Code: 73 01 c3 48 8b 0d b9 85 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 b0 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 89 85 0c 00 f7 d8 64 89 01 48
[391281.448645] RSP: 002b:00007ffee89221f8 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[391281.448646] RAX: ffffffffffffffda RBX: 0000563b1fdfb760 RCX: 00007f8b03328847
[391281.448647] RDX: 0000000000000000 RSI: 0000000000000a00 RDI: 0000563b1fdfb7c8
[391281.448648] RBP: 0000000000000200 R08: 00007f8b033f1cc0 R09: 00000000000000b0
[391281.448648] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffee8922448
[391281.448649] R13: 00007ffee89226f9 R14: 0000563b1fdfb2a0 R15: 00007ffee8922450
[391281.448650]  </TASK>
[391281.448650] ---[ end trace 0000000000000000 ]---
[391281.498665] sof-audio-pci-intel-tgl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100
[391281.498787] sof-audio-pci-intel-tgl 0000:00:1f.3: SoundWire enabled on CannonLake+ platform, using SOF driver
[391281.499065] sof-audio-pci-intel-tgl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if 0x040100
[391281.499072] sysfs: cannot create duplicate filename '/devices/pci0000:00/0000:00:1f.3/dmic-codec'
[391281.499074] CPU: 6 PID: 171388 Comm: kworker/6:0 Tainted: G  R     W          6.3.0-0-amd64 thesofproject/sof#1  Debian 6.3.5-1~exp1
[391281.499078] Hardware name: Dell Inc. XPS 17 9720/FFFFFF, BIOS 1.16.1 03/22/2023
[391281.499079] Workqueue: events sof_probe_work [snd_sof]
[391281.499099] Call Trace:
[391281.499101]  <TASK>
[391281.499104]  dump_stack_lvl+0x47/0x60
[391281.499110]  sysfs_warn_dup+0x5a/0x70
[391281.499115]  sysfs_create_dir_ns+0xce/0xe0
[391281.499120]  kobject_add_internal+0xba/0x2b0
[391281.499124]  kobject_add+0x97/0xf0
[391281.499128]  device_add+0xe4/0x8a0
[391281.499134]  platform_device_add+0x16b/0x260
[391281.499138]  platform_device_register_full+0xc2/0x130
[391281.499141]  hda_dsp_probe+0xe7/0x7f0 [snd_sof_intel_hda_common]
[391281.499155]  sof_probe_work+0x30/0x420 [snd_sof]
[391281.499171]  process_one_work+0x1c5/0x3c0
[391281.499175]  worker_thread+0x51/0x390
[391281.499177]  ? _raw_spin_lock_irqsave+0x27/0x60
[391281.499183]  ? __pfx_worker_thread+0x10/0x10
[391281.499185]  kthread+0xea/0x120
[391281.499188]  ? __pfx_kthread+0x10/0x10
[391281.499192]  ret_from_fork+0x29/0x50
[391281.499198]  </TASK>
[391281.499215] kobject_add_internal failed for dmic-codec with -EEXIST, don't try to register things with the same name in the same directory.
[391281.499220] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to create DMIC device
[391281.499222] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to probe DSP -17
[391281.499225] sof-audio-pci-intel-tgl 0000:00:1f.3: error: sof_probe_work failed err: -17
[391285.007411] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: MCP_CONTROL_SW_RST is not cleared
[391285.007445] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: MCP_CONTROL_CLK_STOP_CLR is not cleared
[391285.007468] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: MCP_CONTROL_HW_RST is not cleared
[391285.485677] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[391285.515296] soundwire_intel soundwire_intel.link.2: IO transfer timed out, cmd 3 device 6 addr 45 len 1
[391285.515319] soundwire sdw-master-2: trf on Slave 6 failed:-110 write addr 45 count 0
[391285.515323] rt1316-sdca sdw:2:025d:1316:01: SDW_SCP_SYSTEMCTRL write failed:-110
[391285.515324] rt1316-sdca sdw:2:025d:1316:01: clock stop prepare failed:-110
[391285.515326] soundwire_intel soundwire_intel.link.2: prepare clock stop failed -110
[391285.515327] soundwire_intel soundwire_intel.link.2: intel_stop_bus: cannot stop clock: -110
[391285.515329] soundwire_intel soundwire_intel.link.2: intel_link_power_down: Unbalanced power-up/down calls
[391285.515348] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 3 device 4 addr 45 len 1
[391285.515367] soundwire sdw-master-1: trf on Slave 4 failed:-110 write addr 45 count 0
[391285.515369] rt1316-sdca sdw:1:025d:1316:01: SDW_SCP_SYSTEMCTRL write failed:-110
[391285.515370] rt1316-sdca sdw:1:025d:1316:01: clock stop prepare failed:-110
[391285.515371] soundwire_intel soundwire_intel.link.1: prepare clock stop failed -110
[391285.515372] soundwire_intel soundwire_intel.link.1: intel_stop_bus: cannot stop clock: -110
[391285.515415] soundwire_intel soundwire_intel.link.1: intel_link_power_down: Unbalanced power-up/down calls
[391289.342559] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7

Longer log:
dmesg.txt

@eighthave eighthave added the bug Something isn't working label Jun 14, 2023
@plbossart
Copy link
Member

@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?

@eighthave
Copy link
Author

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:

  • Playing Music while working
  • Notification Sounds
  • Video calls with browsers and apps.
  • Sometimes videos in the browser.

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.

@plbossart
Copy link
Member

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.

@eighthave
Copy link
Author

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.

@plbossart
Copy link
Member

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.

@eighthave
Copy link
Author

eighthave commented Jun 15, 2023 via email

@eighthave
Copy link
Author

eighthave commented Jun 20, 2023

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

@lgirdwood
Copy link
Member

@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

@plbossart
Copy link
Member

Likely something happening over HDMI @lgirdwood, but that would be very different to the initial issue reported.

@lgirdwood
Copy link
Member

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.

@eighthave
Copy link
Author

eighthave commented Jul 5, 2023

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.

@plbossart
Copy link
Member

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.

@eighthave
Copy link
Author

Here is a very lightly edited alsa-info (for privacy)
alsa-info.txt.zip

@lgirdwood
Copy link
Member

@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) ?

@plbossart
Copy link
Member

plbossart commented Jul 6, 2023

@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.

@eighthave
Copy link
Author

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

@plbossart
Copy link
Member

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.

@eighthave
Copy link
Author

eighthave commented Jul 6, 2023 via email

@plbossart
Copy link
Member

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

@plbossart
Copy link
Member

Can you provide the result of

ls /sys/bus/soundwire/devices

that will tell us what your configuration is, thank you @eighthave

@eighthave
Copy link
Author

 ~ $ 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

plbossart referenced this issue in plbossart/sound Jul 6, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
@plbossart
Copy link
Member

I don't know if this fixes your issue @eighthave but at least the patch in PR #4463 should make the jack detection work a lot better. One day we'll get the list of all SKUs, hope springs eternal, etc.

plbossart referenced this issue Jul 13, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
bardliao referenced this issue in bardliao/linux Jul 20, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
Reviewed-by: Bard Liao <[email protected]>
bardliao referenced this issue in bardliao/linux Jul 20, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
Reviewed-by: Bard Liao <[email protected]>
bardliao referenced this issue Jul 26, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
Reviewed-by: Bard Liao <[email protected]>
bardliao referenced this issue Jul 31, 2023
Yet another missing configuration, with the standard configuration

link0: rt711-sdca
link 1 and 2: rt1316-sdca
link3: rt714-sdca

Link: https://github.com/thesofproject/sof/issues/7799
Signed-off-by: Pierre-Louis Bossart <[email protected]>
Reviewed-by: Bard Liao <[email protected]>
@lgirdwood
Copy link
Member

@plbossart is this fix merged ? Can we close ?

@eighthave
Copy link
Author

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.

@lgirdwood
Copy link
Member

@eighthave we can leave it open for the next few weeks, would be good to get further testing.

@changedsoul
Copy link

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"

@plbossart
Copy link
Member

@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.

@eighthave
Copy link
Author

eighthave commented Mar 5, 2024 via email

@changedsoul
Copy link

@plbossart Sorry for lack of info. Here is the original issue I had with sound : #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.

@changedsoul
Copy link

@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.

@eighthave
Copy link
Author

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

@eighthave
Copy link
Author

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.

@eighthave
Copy link
Author

eighthave commented Jun 5, 2024

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

@eighthave eighthave reopened this Jun 5, 2024
@plbossart
Copy link
Member

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

@eighthave
Copy link
Author

syslog-alsa.txt.zip

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

@plbossart
Copy link
Member

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.

@plbossart
Copy link
Member

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

@plbossart plbossart added the SDW Applies to SoundWire bus for codec connection label Jun 6, 2024
@eighthave
Copy link
Author

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.

@plbossart
Copy link
Member

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.

@plbossart
Copy link
Member

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?

@plbossart
Copy link
Member

wait, i think we fixed this already.

@eighthave can you please double-check if this patch is in your kernel?

6f4867f 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.

@eighthave
Copy link
Author

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

@ujfalusi
Copy link
Collaborator

this is a kernel issue, moving.

@ujfalusi ujfalusi transferred this issue from thesofproject/sof Oct 22, 2024
@lgirdwood
Copy link
Member

@ujfalusi can this be closed ? i.e. does 6f4867f fix issue and is available for older kernels ?

@ujfalusi
Copy link
Collaborator

@lgirdwood, I'm not sure. 6f4867f do fix something, but even if that patch is in kernel, the runtime PM gets very confused and in a similar way: #5212

Something is not adding up.
I cannot see the point where and how it happens.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working SDW Applies to SoundWire bus for codec connection
Projects
None yet
Development

No branches or pull requests

6 participants