Skip to content

[BUG] ] audio crashes and stops working after sleep (Dell 9720 w/ Alder Lake PCH-P audio) #5212

Closed

Description

@eighthave

Describe the bug

The built-in audio is totally stuck, both the speaker and when I plug in a headset. It seems to be related to when the laptop is put to sleep. When I plug in a USB audio device, everything works fine. I'm the same machine as #5213, but it seems this is a different bug, based on the log output, but with the same or similar results.

To Reproduce

  1. Boot computer
  2. confirm audio works
  3. use the computer normally
  4. put the computer to sleep
  5. wake it up

Audio stuck.

Reproduction Rate

It happens most of the time after a fresh reboot. After a while, it sometimes gets unstuck and stays unstuck for a bit.

Expected behavior

Audio to work fine after sleep, and all the time.

Impact

Built-in audio does not work at all, it makes it impossible to do online meetings, listen to music, watch videos, etc.

Environment

  1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
    • Kernel: Debian's linux-image-amd64 (6.10.11-1~bpo12+1) from bookworm-backports
    • SOF: Debian's firmware-sof-signed (2.2.5-1)
  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

dmesg

audio-stuck-dmesg.txt.zip

# grep -i -e 'ASoC: error' -e soundwire -e pipewire -e alsa /var/log/syslog|grep 2024-10-21
2024-10-21T06:07:25.014047+02:00 monolith kernel: [38714.518345] soundwire_intel soundwire_intel.link.0: intel_pm_prepare: pm_runtime_resume failed: -16
2024-10-21T06:07:25.014048+02:00 monolith kernel: [38714.518364] soundwire_intel soundwire_intel.link.1: intel_pm_prepare: pm_runtime_resume failed: -16
2024-10-21T06:07:25.014048+02:00 monolith kernel: [38714.518372] soundwire_intel soundwire_intel.link.2: intel_pm_prepare: pm_runtime_resume failed: -16
2024-10-21T06:07:25.014049+02:00 monolith kernel: [38714.518378] soundwire_intel soundwire_intel.link.3: intel_pm_prepare: pm_runtime_resume failed: -16
2024-10-21T06:07:25.014049+02:00 monolith kernel: [38714.519961] soundwire_intel soundwire_intel.link.3: intel_suspend: invalid config: parent is suspended
2024-10-21T06:07:25.014050+02:00 monolith kernel: [38714.519970] soundwire_intel soundwire_intel.link.2: intel_suspend: invalid config: parent is suspended
2024-10-21T06:07:25.014050+02:00 monolith kernel: [38714.519977] soundwire_intel soundwire_intel.link.1: intel_suspend: invalid config: parent is suspended
2024-10-21T06:07:25.014051+02:00 monolith kernel: [38714.519983] soundwire_intel soundwire_intel.link.0: intel_suspend: invalid config: parent is suspended
2024-10-21T06:07:25.014064+02:00 monolith kernel: [70600.180063] Modules linked in: snd_usb_audio snd_usbmidi_lib snd_rawmidi hid_jabra typec_displayport cdc_mbim cdc_wdm cdc_ncm cdc_ether usbnet r8152 mii libphy usbhid cdc_acm ccm rfcomm snd_seq_dummy snd_hrtimer snd_seq snd_seq_device cmac algif_hash algif_skcipher af_alg xt_LOG nf_log_syslog xt_tcpudp wireguard xt_conntrack libchacha20poly1305 nf_conntrack chacha_x86_64 poly1305_x86_64 nf_defrag_ipv6 nf_defrag_ipv4 nft_compat curve25519_x86_64 libcurve25519_generic libchacha ip6_udp_tunnel udp_tunnel nf_tables nfnetlink overlay qrtr snd_ctl_led snd_soc_sof_sdw snd_sof_probes snd_soc_intel_hda_dsp_common bnep snd_soc_rt711_sdca snd_soc_rt715_sdca snd_hda_codec_hdmi snd_soc_rt1316_sdw regmap_sdw_mbq regmap_sdw snd_soc_dmic binfmt_misc snd_sof_pci_intel_tgl snd_sof_pci_intel_cnl snd_sof_intel_hda_generic soundwire_intel nls_ascii soundwire_generic_allocation soundwire_cadence nls_cp437 vfat snd_sof_intel_hda_common fat snd_sof_intel_hda_mlink snd_sof_intel_hda snd_sof_pci iwlmvm snd_sof_xtensa_dsp snd_sof snd_sof_utils
2024-10-21T06:07:25.014065+02:00 monolith kernel: [70600.180096]  snd_soc_hdac_hda snd_soc_acpi_intel_match snd_soc_acpi soundwire_bus mac80211 snd_soc_avs intel_uncore_frequency intel_uncore_frequency_common x86_pkg_temp_thermal snd_soc_hda_codec intel_powerclamp snd_hda_ext_core coretemp snd_soc_core kvm_intel snd_compress snd_pcm_dmaengine libarc4 uvcvideo snd_hda_intel kvm snd_intel_dspcfg snd_intel_sdw_acpi videobuf2_vmalloc snd_hda_codec uvc videobuf2_memops videobuf2_v4l2 snd_hda_core iwlwifi snd_hwdep btusb snd_pcm videodev hid_sensor_als btrtl hid_sensor_trigger mei_pxp processor_thermal_device_pci btintel mei_hdcp dell_laptop iTCO_wdt hid_sensor_iio_common snd_timer processor_thermal_device industrialio_triggered_buffer intel_pmc_bxt btbcm dell_wmi rapl kfifo_buf processor_thermal_wt_hint intel_rapl_msr dell_smbios videobuf2_common dell_wmi_sysman btmtk dcdbas intel_cstate bluetooth intel_uncore mc dell_wmi_ddv dell_smm_hwmon pcspkr firmware_attributes_class dell_wmi_descriptor wmi_bmof industrialio iTCO_vendor_support cfg80211 processor_thermal_rfim ucsi_acpi
2024-10-21T06:07:25.014116+02:00 monolith kernel: [70600.430644] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
2024-10-21T06:07:25.014116+02:00 monolith kernel: [70600.430659] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
2024-10-21T06:07:25.014140+02:00 monolith kernel: [70600.430664] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume returns -11
2024-10-21T06:07:25.014142+02:00 monolith kernel: [70600.430682] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
2024-10-21T06:07:25.014142+02:00 monolith kernel: [70600.431792] soundwire_intel soundwire_intel.link.1: Failed to power up link: -11
2024-10-21T06:07:25.014142+02:00 monolith kernel: [70600.431796] soundwire_intel soundwire_intel.link.1: intel_resume failed: -11
2024-10-21T06:07:25.014143+02:00 monolith kernel: [70600.431800] soundwire_intel soundwire_intel.link.1: PM: dpm_run_callback(): pm_generic_resume returns -11
2024-10-21T06:07:25.014143+02:00 monolith kernel: [70600.431811] soundwire_intel soundwire_intel.link.1: PM: failed to resume: error -11
2024-10-21T06:07:25.014144+02:00 monolith kernel: [70600.432911] soundwire_intel soundwire_intel.link.2: Failed to power up link: -11
2024-10-21T06:07:25.014144+02:00 monolith kernel: [70600.432915] soundwire_intel soundwire_intel.link.2: intel_resume failed: -11
2024-10-21T06:07:25.014144+02:00 monolith kernel: [70600.432919] soundwire_intel soundwire_intel.link.2: PM: dpm_run_callback(): pm_generic_resume returns -11
2024-10-21T06:07:25.014145+02:00 monolith kernel: [70600.432928] soundwire_intel soundwire_intel.link.2: PM: failed to resume: error -11
2024-10-21T06:07:25.014145+02:00 monolith kernel: [70600.434038] soundwire_intel soundwire_intel.link.3: Failed to power up link: -11
2024-10-21T06:07:25.014145+02:00 monolith kernel: [70600.434044] soundwire_intel soundwire_intel.link.3: intel_resume failed: -11
2024-10-21T06:07:25.014146+02:00 monolith kernel: [70600.434050] soundwire_intel soundwire_intel.link.3: PM: dpm_run_callback(): pm_generic_resume returns -11
2024-10-21T06:07:25.014146+02:00 monolith kernel: [70600.434068] soundwire_intel soundwire_intel.link.3: PM: failed to resume: error -11
2024-10-21T06:07:25.016435+02:00 monolith kernel: [70600.441685] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: IP_MCP_CONTROL_SW_RST is not cleared
2024-10-21T06:07:25.016437+02:00 monolith kernel: [70600.441690] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: MCP_CONTROL_CLK_STOP_CLR is not cleared
2024-10-21T06:07:25.016437+02:00 monolith kernel: [70600.441692] soundwire_intel soundwire_intel.link.3: sdw_cdns_clock_stop failed: MCP_CONTROL_HW_RST is not cleared
2024-10-21T06:07:25.016438+02:00 monolith kernel: [70600.441860] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: IP_MCP_CONTROL_SW_RST is not cleared
2024-10-21T06:07:25.016439+02:00 monolith kernel: [70600.441863] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: MCP_CONTROL_CLK_STOP_CLR is not cleared
2024-10-21T06:07:25.016439+02:00 monolith kernel: [70600.441865] soundwire_intel soundwire_intel.link.1: sdw_cdns_clock_stop failed: MCP_CONTROL_HW_RST is not cleared
2024-10-21T06:07:25.548431+02:00 monolith kernel: [70600.971116] soundwire_intel soundwire_intel.link.3: IO transfer timed out, cmd 3 device 7 addr 45 len 1
2024-10-21T06:07:25.548440+02:00 monolith kernel: [70600.971139] soundwire sdw-master-0-3: trf on Slave 7 failed:-110 write addr 45 count 0
2024-10-21T06:07:25.548441+02:00 monolith kernel: [70600.971145] soundwire_intel soundwire_intel.link.3: prepare clock stop failed -110
2024-10-21T06:07:25.548442+02:00 monolith kernel: [70600.971147] soundwire_intel soundwire_intel.link.3: intel_stop_bus: cannot stop clock: -110
2024-10-21T06:07:25.548442+02:00 monolith kernel: [70600.971150] soundwire_intel soundwire_intel.link.3: intel_link_power_down: Unbalanced power-up/down calls
2024-10-21T06:07:25.548443+02:00 monolith kernel: [70600.971169] soundwire_intel soundwire_intel.link.2: IO transfer timed out, cmd 3 device 1 addr 45 len 1
2024-10-21T06:07:25.548443+02:00 monolith kernel: [70600.971190] soundwire sdw-master-0-2: trf on Slave 1 failed:-110 write addr 45 count 0
2024-10-21T06:07:25.548444+02:00 monolith kernel: [70600.971194] soundwire_intel soundwire_intel.link.2: prepare clock stop failed -110
2024-10-21T06:07:25.548444+02:00 monolith kernel: [70600.971195] soundwire_intel soundwire_intel.link.2: intel_stop_bus: cannot stop clock: -110
2024-10-21T06:07:25.548444+02:00 monolith kernel: [70600.971200] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 3 device 1 addr 45 len 1
2024-10-21T06:07:25.548444+02:00 monolith kernel: [70600.971213] soundwire sdw-master-0-1: trf on Slave 1 failed:-110 write addr 45 count 0
2024-10-21T06:07:25.548445+02:00 monolith kernel: [70600.971218] soundwire_intel soundwire_intel.link.1: prepare clock stop failed -110
2024-10-21T06:07:25.548445+02:00 monolith kernel: [70600.971219] soundwire_intel soundwire_intel.link.1: intel_stop_bus: cannot stop clock: -110
2024-10-21T06:07:25.548446+02:00 monolith kernel: [70600.971243] soundwire_intel soundwire_intel.link.2: intel_link_power_down: Unbalanced power-up/down calls
2024-10-21T06:07:25.548446+02:00 monolith kernel: [70600.971251] soundwire_intel soundwire_intel.link.0: IO transfer timed out, cmd 3 device 6 addr 45 len 1
2024-10-21T06:07:25.548446+02:00 monolith kernel: [70600.971257] soundwire sdw-master-0-0: trf on Slave 6 failed:-110 write addr 45 count 0
2024-10-21T06:07:25.548447+02:00 monolith kernel: [70600.971260] soundwire_intel soundwire_intel.link.0: prepare clock stop failed -110
2024-10-21T06:07:25.548447+02:00 monolith kernel: [70600.971260] soundwire_intel soundwire_intel.link.0: intel_stop_bus: cannot stop clock: -110
2024-10-21T06:07:25.548451+02:00 monolith kernel: [70600.975027] soundwire_intel soundwire_intel.link.1: intel_link_power_down: Unbalanced power-up/down calls
2024-10-21T06:07:25.552534+02:00 monolith kernel: [70600.975107] soundwire_intel soundwire_intel.link.0: intel_link_power_down: Unbalanced power-up/down calls
2024-10-21T06:09:36.673653+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:09:36.673794+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:09:36.673856+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:1863:spa_alsa_enum_format]: opened:0 format:0 started:0
2024-10-21T06:09:36.673891+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:09:36.673919+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:09:36.673945+02:00 monolith pipewire[2752]: spa.audioadapter: params Spa:Enum:ParamId:EnumFormat: 0:0 (follower format) Device or resource busy
2024-10-21T06:09:36.673979+02:00 monolith pipewire[2752]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Speaker__sink-59) suspended -> error (Start error: Device or resource busy)
2024-10-21T06:09:36.676504+02:00 monolith kernel: [70732.098641] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:09:36.676511+02:00 monolith kernel: [70732.098648]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:09:36.676511+02:00 monolith kernel: [70732.098649]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:09:36.676512+02:00 monolith kernel: [70732.098651]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:09:36.676512+02:00 monolith kernel: [70732.098715] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:09:36.676513+02:00 monolith kernel: [70732.098716]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:09:36.676513+02:00 monolith kernel: [70732.098717]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:09:36.676513+02:00 monolith kernel: [70732.098718]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:09:41.680983+02:00 monolith pipewire[2752]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Speaker__sink-59) suspended -> error ((null))
2024-10-21T06:09:41.681438+02:00 monolith pipewire[2752]: pw.link: 0x5618ead1c500: one of the nodes is in error out:idle in:error
2024-10-21T06:09:41.681588+02:00 monolith pipewire[2752]: pw.link: 0x5618e99fe3f0: one of the nodes is in error out:idle in:error
2024-10-21T06:11:44.666153+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:11:44.667014+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:11:44.667035+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:1863:spa_alsa_enum_format]: opened:0 format:0 started:0
2024-10-21T06:11:44.667051+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:11:44.667064+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:11:44.667077+02:00 monolith pipewire[2752]: spa.audioadapter: params Spa:Enum:ParamId:EnumFormat: 0:0 (follower format) Device or resource busy
2024-10-21T06:11:44.667091+02:00 monolith pipewire[2752]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Speaker__sink-59) suspended -> error (Start error: Device or resource busy)
2024-10-21T06:11:44.668417+02:00 monolith kernel: [70860.089754] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:11:44.668420+02:00 monolith kernel: [70860.089762]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:11:44.668421+02:00 monolith kernel: [70860.089765]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:11:44.668421+02:00 monolith kernel: [70860.089767]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:11:44.668422+02:00 monolith kernel: [70860.089851] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:11:44.668422+02:00 monolith kernel: [70860.089854]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:11:44.668422+02:00 monolith kernel: [70860.089856]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:11:44.668423+02:00 monolith kernel: [70860.089857]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:11:49.673476+02:00 monolith pipewire[2752]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Speaker__sink-59) suspended -> error ((null))
2024-10-21T06:11:49.673666+02:00 monolith pipewire[2752]: pw.link: 0x5618ea3febe0: one of the nodes is in error out:idle in:error
2024-10-21T06:11:49.673732+02:00 monolith pipewire[2752]: pw.link: 0x5618ea3f82d0: one of the nodes is in error out:idle in:error
2024-10-21T06:12:01.259980+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:12:01.260125+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:12:01.260150+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:1863:spa_alsa_enum_format]: opened:0 format:0 started:0
2024-10-21T06:12:01.260172+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:12:01.260190+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:1098:spa_alsa_open]: '_ucm0001.hw:sofsoundwire,2': playback open failed: Device or resource busy
2024-10-21T06:12:01.260209+02:00 monolith pipewire[2752]: spa.audioadapter: params Spa:Enum:ParamId:EnumFormat: 0:0 (follower format) Device or resource busy
2024-10-21T06:12:01.260228+02:00 monolith pipewire[2752]: pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Speaker__sink-59) suspended -> error (Start error: Device or resource busy)
2024-10-21T06:12:01.260425+02:00 monolith kernel: [70876.683291] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:12:01.260434+02:00 monolith kernel: [70876.683304]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:12:01.260435+02:00 monolith kernel: [70876.683307]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:12:01.260435+02:00 monolith kernel: [70876.683309]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:12:01.260436+02:00 monolith kernel: [70876.683372] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:12:01.260437+02:00 monolith kernel: [70876.683373]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:12:01.260437+02:00 monolith kernel: [70876.683374]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:12:01.260439+02:00 monolith kernel: [70876.683376]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:12:03.706209+02:00 monolith pipewire[2752]: pw.link: 0x5618ea3febe0: one of the nodes is in error out:suspended in:error
2024-10-21T06:12:03.706346+02:00 monolith pipewire[2752]: pw.link: 0x5618e991e780: one of the nodes is in error out:suspended in:error
2024-10-21T06:12:38.504386+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1096:spa_alsa_open]: 0x5618e978c408: ALSA device open '_ucm0001.hw:sofsoundwire,2' playback
2024-10-21T06:12:38.504419+02:00 monolith kernel: [70913.927228] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:12:38.504433+02:00 monolith kernel: [70913.927235]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:12:38.504434+02:00 monolith kernel: [70913.927237]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:12:38.504434+02:00 monolith kernel: [70913.927238]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16
2024-10-21T06:12:38.504435+02:00 monolith kernel: [70913.927279] soundwire_intel soundwire_intel.link.1: ASoC: error at snd_soc_pcm_component_pm_runtime_get on soundwire_intel.link.1: -16
2024-10-21T06:12:38.504442+02:00 monolith kernel: [70913.927281]  SDW1-Playback: ASoC: error at __soc_pcm_open on SDW1-Playback: -16
2024-10-21T06:12:38.504443+02:00 monolith kernel: [70913.927282]  Speaker: ASoC: error at dpcm_be_dai_startup on Speaker: -16
2024-10-21T06:12:38.504443+02:00 monolith kernel: [70913.927282]  Speaker: ASoC: error at dpcm_fe_dai_startup on Speaker: -16

Activity

  1. lgirdwood commented on Oct 21, 2024

    @lgirdwood
    Member

    @eighthave lots of soundwire errors in the log - looks like the link fails to power up after suspend and then cascades. This could be the SDW controller or SDW codec, can you confirm SDW codec ID ?

    2024-10-20T12:07:37.184178+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Hardware PCM card 0 'sof-soundwire' device 2 subdevice 0
    2024-10-20T12:07:37.184208+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Its setup is:
    2024-10-20T12:07:37.184234+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stream       : PLAYBACK
    2024-10-20T12:07:37.184265+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   access       : MMAP_INTERLEAVED
    2024-10-20T12:07:37.184292+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   format       : S32_LE
    2024-10-20T12:07:37.184319+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   subformat    : STD
    2024-10-20T12:07:37.184349+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   channels     : 2
    2024-10-20T12:07:37.184374+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   rate         : 48000
    2024-10-20T12:07:37.184400+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   exact rate   : 48000 (48000/1)
    2024-10-20T12:07:37.184425+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   msbits       : 32
    2024-10-20T12:07:37.184453+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   buffer_size  : 8192
    2024-10-20T12:07:37.184477+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_size  : 1024
    2024-10-20T12:07:37.184504+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_time  : 21333
    2024-10-20T12:07:37.824495+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_mode  : ENABLE
    2024-10-20T12:07:37.824572+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_type  : MONOTONIC
    2024-10-20T12:07:37.824595+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_step  : 1
    2024-10-20T12:07:37.824609+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   avail_min    : 1024
    2024-10-20T12:07:37.824623+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_event : 0
    2024-10-20T12:07:37.824642+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   start_threshold  : 9223372036854775807
    2024-10-20T12:07:37.824656+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stop_threshold   : 8192
    2024-10-20T12:07:37.824673+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_threshold: 0
    2024-10-20T12:07:37.824687+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_size : 0
    2024-10-20T12:07:37.824705+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   boundary     : 4611686018427387904
    2024-10-20T12:07:37.824720+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   appl_ptr     : 75776
    2024-10-20T12:07:37.824737+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   hw_ptr       : 92368
    2024-10-20T12:07:37.824753+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:37.825848+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Connection timed out
    2024-10-20T12:07:37.825917+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:37.826151+02:00 monolith kernel: [ 5813.122579] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:37.830144+02:00 monolith kernel: [ 5813.124629] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
    2024-10-20T12:07:38.334962+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Invalid argument
    2024-10-20T12:07:38.335099+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:38.338267+02:00 monolith kernel: [ 5813.632970] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:38.850458+02:00 monolith kernel: [ 5814.144538] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:39.359285+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Connection timed out
    2024-10-20T12:07:39.359458+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:3690:spa_alsa_pause]: 0x5618e978c408: pause
    2024-10-20T12:07:39.359533+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2475:do_drop]: 0x5618e978c408: snd_pcm_drop linked:0
    2024-10-20T12:07:39.359590+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm-sink.c:750:impl_node_port_set_io]: 0x5618e978c408: io 1 (nil) 0
    2024-10-20T12:07:39.359655+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm-sink.c:575:port_set_format]: clear format
    2024-10-20T12:07:39.359718+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1164:spa_alsa_close]: 0x5618e978c408: Device 'hw:sofsoundwire,2p' closing
    2024-10-20T12:07:39.362397+02:00 monolith kernel: [ 5814.656906] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:44.994261+02:00 monolith kernel: [ 5820.288414] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -110
    2024-10-20T12:27:43.393697+02:00 monolith kernel: [ 7016.089097] soundwire_intel soundwire_intel.link.0: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393698+02:00 monolith kernel: [ 7016.089117] soundwire_intel soundwire_intel.link.1: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393700+02:00 monolith kernel: [ 7016.089126] soundwire_intel soundwire_intel.link.2: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393701+02:00 monolith kernel: [ 7016.089136] soundwire_intel soundwire_intel.link.3: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393702+02:00 monolith kernel: [ 7016.091375] soundwire_intel soundwire_intel.link.3: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393704+02:00 monolith kernel: [ 7016.091395] soundwire_intel soundwire_intel.link.2: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393707+02:00 monolith kernel: [ 7016.091404] soundwire_intel soundwire_intel.link.1: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393708+02:00 monolith kernel: [ 7016.091414] soundwire_intel soundwire_intel.link.0: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393722+02:00 monolith kernel: [ 7017.258797] soundwire_intel soundwire_intel.link.0: runtime PM trying to activate child device soundwire_intel.link.0 but parent (0000:00:1f.3) is not active
    2024-10-20T12:27:43.393724+02:00 monolith kernel: [ 7017.259839] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
    2024-10-20T12:27:43.393725+02:00 monolith kernel: [ 7017.259850] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
    2024-10-20T12:27:43.393726+02:00 monolith kernel: [ 7017.259857] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume returns -11
    2024-10-20T12:27:43.393727+02:00 monolith kernel: [ 7017.259873] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
    2024-10-20T12:27:43.393729+02:00 monolith kernel: [ 7017.259875] soundwire_intel soundwire_intel.link.1: runtime PM trying to activate child device soundwire_intel.link.1 but parent (0000:00:1f.3) is not active
    
  2. bardliao commented on Oct 22, 2024

    @bardliao
    Collaborator

    @eighthave We need more debug trace to get what happened. Can you copy sof-dyndbg.conf.txt as /etc/modprobe.d/sof-dyndbg.conf reboot and attach the full kernel log with the issue? Does the issue happen only when a headset is plugged in? Or it happens without headset, too?

    2024-10-20T12:27:43.393697+02:00 monolith kernel: [ 7016.089097] soundwire_intel soundwire_intel.link.0: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393698+02:00 monolith kernel: [ 7016.089117] soundwire_intel soundwire_intel.link.1: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393700+02:00 monolith kernel: [ 7016.089126] soundwire_intel soundwire_intel.link.2: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393701+02:00 monolith kernel: [ 7016.089136] soundwire_intel soundwire_intel.link.3: intel_pm_prepare: pm_runtime_resume failed: -16
    

    and

    2024-10-20T12:27:43.393724+02:00 monolith kernel: [ 7017.259839] soundwire_intel soundwire_intel.link.0: Failed to power up link: -11
    2024-10-20T12:27:43.393725+02:00 monolith kernel: [ 7017.259850] soundwire_intel soundwire_intel.link.0: intel_resume failed: -11
    2024-10-20T12:27:43.393726+02:00 monolith kernel: [ 7017.259857] soundwire_intel soundwire_intel.link.0: PM: dpm_run_callback(): pm_generic_resume returns -11
    2024-10-20T12:27:43.393727+02:00 monolith kernel: [ 7017.259873] soundwire_intel soundwire_intel.link.0: PM: failed to resume: error -11
    

    Where the error code -16 is -EBUSY and -11 is -EAGAIN. I suspect something has been wrong before the error was reported.

  3. eighthave commented on Oct 22, 2024

    @eighthave
    Author

    It happened with and without a headset plugged into the 3.5mm headphone jack. I don't think it is related to plugging it in either, like I could reboot and not plug headphones in, and it would happen. I might be wrong, but I think that's the case.

    I've added that modprobe config, and I'll reply once it happens again. It seems to be working OK now after a reboot.

    @lgirdwood I'm not sure what "SDW codec ID" is exactly, could it be "rt714"?

  4. ujfalusi commented on Oct 22, 2024

    @ujfalusi
    Collaborator

    Looks like a kernel issue, moving.

  5. transferred this issue fromthesofproject/sofon Oct 22, 2024
  6. ujfalusi commented on Oct 22, 2024

    @ujfalusi
    Collaborator

    @eighthave, couple of questions to help us to progress:

    • is this a regression? Iow, the issue appeared after kernel/sof-firmware/pipewire/alsa-ucm-utils update or it is a new install and no prior record is known
    • can you attach the output of alsa-info.sh ?
    • can you attach a kernel log right after boot (with the sof-dyndbg.conf in place)?
    • The computer sleep means normal suspend (s2_idle) or hibernation or just leaving the laptop as idle
    • Are you able to test older or newer kernel?

    Notes: what PW does is quite strange as it opens and closes the audio quite frequently, in just about a second.

    The last OK start:

    2024-10-20T12:07:35.253119+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2445:do_prepare]: 0x5618e978c408: start threshold:2048 duration:2048 rate:48000 follower:0 match:0 resample:0
    2024-10-20T12:07:35.253137+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2356:set_swparams]: state after sw_params:
    2024-10-20T12:07:35.253154+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Hardware PCM card 0 'sof-soundwire' device 2 subdevice 0
    2024-10-20T12:07:35.253177+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Its setup is:
    2024-10-20T12:07:35.253191+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stream       : PLAYBACK
    2024-10-20T12:07:35.253203+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   access       : MMAP_INTERLEAVED
    2024-10-20T12:07:35.253223+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   format       : S32_LE
    2024-10-20T12:07:35.253247+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   subformat    : STD
    2024-10-20T12:07:35.253262+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   channels     : 2
    2024-10-20T12:07:35.253278+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   rate         : 48000
    2024-10-20T12:07:35.253292+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   exact rate   : 48000 (48000/1)
    2024-10-20T12:07:35.253310+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   msbits       : 32
    2024-10-20T12:07:35.253323+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   buffer_size  : 8192
    2024-10-20T12:07:35.253336+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_size  : 1024
    2024-10-20T12:07:35.253355+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_time  : 21333
    2024-10-20T12:07:35.253368+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_mode  : ENABLE
    2024-10-20T12:07:35.253386+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_type  : MONOTONIC
    2024-10-20T12:07:35.253399+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_step  : 1
    2024-10-20T12:07:35.253418+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   avail_min    : 1024
    2024-10-20T12:07:35.253431+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_event : 0
    2024-10-20T12:07:35.253447+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   start_threshold  : 9223372036854775807
    2024-10-20T12:07:35.253464+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stop_threshold   : 8192
    2024-10-20T12:07:35.253478+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_threshold: 0
    2024-10-20T12:07:35.253491+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_size : 0
    2024-10-20T12:07:35.253505+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   boundary     : 4611686018427387904
    2024-10-20T12:07:35.253518+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   appl_ptr     : 6144
    2024-10-20T12:07:35.253533+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   hw_ptr       : 32544
    2024-10-20T12:07:35.257137+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:36.195343+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2739:update_time]: hw:sofsoundwire,2p: follower:0 match:0 rate:0,999488 bw:0,128000 thr:2048 del:2064 target:2048 err:16,000000 max:1024,000000
    2024-10-20T12:07:37.183989+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2475:do_drop]: 0x5618e978c408: snd_pcm_drop linked:0
    

    First playback fail:

    2024-10-20T12:07:37.184074+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2445:do_prepare]: 0x5618e978c408: start threshold:2048 duration:2048 rate:48000 follower:0 match:0 resample:0
    2024-10-20T12:07:37.184144+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2356:set_swparams]: state after sw_params:
    2024-10-20T12:07:37.184178+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Hardware PCM card 0 'sof-soundwire' device 2 subdevice 0
    2024-10-20T12:07:37.184208+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]: Its setup is:
    2024-10-20T12:07:37.184234+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stream       : PLAYBACK
    2024-10-20T12:07:37.184265+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   access       : MMAP_INTERLEAVED
    2024-10-20T12:07:37.184292+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   format       : S32_LE
    2024-10-20T12:07:37.184319+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   subformat    : STD
    2024-10-20T12:07:37.184349+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   channels     : 2
    2024-10-20T12:07:37.184374+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   rate         : 48000
    2024-10-20T12:07:37.184400+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   exact rate   : 48000 (48000/1)
    2024-10-20T12:07:37.184425+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   msbits       : 32
    2024-10-20T12:07:37.184453+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   buffer_size  : 8192
    2024-10-20T12:07:37.184477+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_size  : 1024
    2024-10-20T12:07:37.184504+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_time  : 21333
    2024-10-20T12:07:37.824495+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_mode  : ENABLE
    2024-10-20T12:07:37.824572+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   tstamp_type  : MONOTONIC
    2024-10-20T12:07:37.824595+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_step  : 1
    2024-10-20T12:07:37.824609+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   avail_min    : 1024
    2024-10-20T12:07:37.824623+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   period_event : 0
    2024-10-20T12:07:37.824642+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   start_threshold  : 9223372036854775807
    2024-10-20T12:07:37.824656+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   stop_threshold   : 8192
    2024-10-20T12:07:37.824673+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_threshold: 0
    2024-10-20T12:07:37.824687+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   silence_size : 0
    2024-10-20T12:07:37.824705+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   boundary     : 4611686018427387904
    2024-10-20T12:07:37.824720+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   appl_ptr     : 75776
    2024-10-20T12:07:37.824737+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:641:log_write]:   hw_ptr       : 92368
    2024-10-20T12:07:37.824753+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:37.825848+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Connection timed out
    2024-10-20T12:07:37.825917+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:37.826151+02:00 monolith kernel: [ 5813.122579] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:37.830144+02:00 monolith kernel: [ 5813.124629] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
    2024-10-20T12:07:38.334962+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Invalid argument
    2024-10-20T12:07:38.335099+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2488:do_start]: 0x5618e978c408: snd_pcm_start linked:0
    2024-10-20T12:07:38.338267+02:00 monolith kernel: [ 5813.632970] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:38.850458+02:00 monolith kernel: [ 5814.144538] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:39.359285+02:00 monolith pipewire[2752]: E spa.alsa [alsa-pcm.c:2490:do_start]: hw:sofsoundwire,2p: snd_pcm_start: Connection timed out
    2024-10-20T12:07:39.359458+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:3690:spa_alsa_pause]: 0x5618e978c408: pause
    2024-10-20T12:07:39.359533+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm.c:2475:do_drop]: 0x5618e978c408: snd_pcm_drop linked:0
    2024-10-20T12:07:39.359590+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm-sink.c:750:impl_node_port_set_io]: 0x5618e978c408: io 1 (nil) 0
    2024-10-20T12:07:39.359655+02:00 monolith pipewire[2752]: D spa.alsa [alsa-pcm-sink.c:575:port_set_format]: clear format
    2024-10-20T12:07:39.359718+02:00 monolith pipewire[2752]: I spa.alsa [alsa-pcm.c:1164:spa_alsa_close]: 0x5618e978c408: Device 'hw:sofsoundwire,2p' closing
    2024-10-20T12:07:39.362397+02:00 monolith kernel: [ 5814.656906] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
    2024-10-20T12:07:44.994261+02:00 monolith kernel: [ 5820.288414] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -110
    

    Quite long delay to report pm runtime resume fail:

    2024-10-20T12:27:43.393697+02:00 monolith kernel: [ 7016.089097] soundwire_intel soundwire_intel.link.0: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393698+02:00 monolith kernel: [ 7016.089117] soundwire_intel soundwire_intel.link.1: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393700+02:00 monolith kernel: [ 7016.089126] soundwire_intel soundwire_intel.link.2: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393701+02:00 monolith kernel: [ 7016.089136] soundwire_intel soundwire_intel.link.3: intel_pm_prepare: pm_runtime_resume failed: -16
    2024-10-20T12:27:43.393702+02:00 monolith kernel: [ 7016.091375] soundwire_intel soundwire_intel.link.3: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393704+02:00 monolith kernel: [ 7016.091395] soundwire_intel soundwire_intel.link.2: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393707+02:00 monolith kernel: [ 7016.091404] soundwire_intel soundwire_intel.link.1: intel_suspend: invalid config: parent is suspended
    2024-10-20T12:27:43.393708+02:00 monolith kernel: [ 7016.091414] soundwire_intel soundwire_intel.link.0: intel_suspend: invalid config: parent is suspended
    
  7. eighthave commented on Oct 22, 2024

    @eighthave
    Author

    is this a regression? Iow, the issue appeared after kernel/sof-firmware/pipewire/alsa-ucm-utils update or it is a new install and no prior record is known

    This is an older install, there have been a series of issues with the sound that have been getting fixed. This seems like familiar symptoms but with different log output.

    can you attach the output of alsa-info.sh ?

    http://alsa-project.org/db/?f=5f5f365f50016df24719b2579b777ff655d6b7d5

    can you attach a kernel log right after boot (with the sof-dyndbg.conf in place)?

    Yes, I'll do so after I reboot next time (I'm in the middle of my work day)

    The computer sleep means normal suspend (s2_idle) or hibernation or just leaving the laptop as idle

    Sleep as in closing the laptop lid. I use a default Debian config for that, so I believe that means s2_idle

    Are you able to test older or newer kernel?

    I'm using Debian's kernels with Secure Boot on, so I could test those. With older kernels, I had other related issues, so it probably won't be so helpful, e.g #5213

  8. added
    P2Critical bugs or normal features
    on Oct 22, 2024
  9. bardliao commented on Oct 24, 2024

    @bardliao
    Collaborator

    I installed Debian 12 on my Tiger Lake laptop which has the same audio codecs as Dell 9720. And audio works just fine. I start YouTube, and closed the lid, then open it after some minutes. YouTube was continue playing with no issue. I am using the default kernel from the Debian 12 image.
    Linux version 6.1.0-26-amd64 (debian-kernel@lists.debian.org) (gcc-12 (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP PREEMPT_DYNAMIC Debian 6.1.112-1 (2024-09-30)

  10. lgirdwood commented on Oct 24, 2024

    @lgirdwood
    Member

    @eighthave one other thing to check is that you are up to date with system FW i.e. can you run fwupdmgr as audio software and firmware has many interaction with system FW for PM and HW IO.

  11. eighthave commented on Oct 28, 2024

    @eighthave
    Author

    Good idea. I was running 1.18, now I upgraded to 1.27. I'll report back whether things are working well or not. It is an intermittent issue, so I should probably try for a week before I can say.

  12. ujfalusi commented on Mar 4, 2025

    @ujfalusi
    Collaborator

    @eighthave, do you still experience with crashes?
    I would suggest updating the kernel since that would be the next thing to try if the crashes are still happening.

  13. eighthave commented on Mar 4, 2025

    @eighthave
    Author

    I'm now on 6.12.12+bpo and the latest BIOS, and the range of issues has changed again. In general, things are getting better. I don't seem to have those audio crashes any more. I am now getting complete system freezes, which do seem related to suspend but maybe not audio. More info https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1099342

    I have been having this new related problem which is odd, maybe it is an audio crash. Basically, in the middle of calls (Signal, Jitsi, etc) I could no longer hear anything, but the mic seemed to work. It only seems to have affected a single audio device. Like if I unplug my USB speaker phone, then the built-in audio would pick up and work. It also happened when using only built-in audio. Then it seemed to have fixed itself after some time, perhaps related to me plugging in the USB speaker phone.

  14. ujfalusi commented on Mar 4, 2025

    @ujfalusi
    Collaborator

    @eighthave, that debian bug is pointing to USB (ucsi_send_command_common) related issue, but surely nothing can be ruled out.
    Just to confirm, you have BIOS 1.30.1 version (https://www.dell.com/support/home/en-us/drivers/driversdetails?driverid=ky0ym&oscode=w2021&productcode=xps-17-9720-laptop)?

    The issue you describe do sound odd and it sounds like it is not SOF related as it similarly affects USB audio.

    When the mic stops working, do you see anything in the kernel log? I see that you are using locked down kernel, can that have undesired side effects?

  15. eighthave commented on Mar 4, 2025

    @eighthave
    Author
  16. eighthave commented on Jul 12, 2025

    @eighthave
    Author

    I'm on 6.12.32 for a bit now, and I think this is fixed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

P2Critical bugs or normal featuresbugSomething isn't working

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions