Audio frozen sometimes after sleep

[life00]

Hello. I am running Fedora Asahi Linux (macbook pro M1 2020) and I've recently noticed a very annoying bug happening after sleep with my external headphones.

After sleep there is no audio and when I unplug my headphones they stay as if plugged, so the whole config kind of becomes frozen. Restarting pipewire does not help. The only solution I found is to restart.

This sometimes happens when I leave audio running and then close the lid, or when I unplug or plug the cable during sleep. I should also note that I am connecting my headphones directly over audio jack.

I found some logs that seem to be related to this issue: https://0x0.st/HORy.log

I can provide more details but please explain what specifically.

[life00]

I just now found another way to temporarily fix it. Just invoke sleep ones again and it somehow fixes the issue.

However it partially fixed the issue. This error log no longer appears:

Sep 22 19:20:44 localhost kernel: cs42l83 0-0048: ASoC: error at snd_soc_component_update_bits on cs42l83.0-0048 for register: [0x00001501] -6
Sep 22 19:20:44 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Sep 22 19:20:44 localhost kernel: cs42l83 0-0048: PLL failed to lock: -6

But the following errors are still persistent:

Sep 22 19:36:36 localhost kernel: Secondary: ASoC: error at snd_soc_link_hw_params on Secondary: -22
Sep 22 19:36:36 localhost kernel: Secondary: ASoC: error at __soc_pcm_hw_params on Secondary: -22
Sep 22 19:36:36 localhost kernel: Secondary: ASoC: error at dpcm_fe_dai_hw_params on Secondary: -22
Sep 22 19:36:36 localhost kernel: Secondary: opening PCM device 'Secondary' with no audio route configured (bad settings applied to the sound card)

[Emirhankayar]

I have exact same model of m1 pro maybe its not right place to ask but i would like to ask because i have been using asahi for 3 months without audio except for bluetooth devices. Did you enable audio for the speakers? I dont have enough courage to try it(dont want to break the speakers). If you enabled asahi audio do you have any errors or is there anything unusual with your device?

[life00]

I have exact same model of m1 pro maybe its not right place to ask but i would like to ask because i have been using asahi for 3 months without audio except for bluetooth devices.

@Emirhankayar I do not use bluetooth for security reasons, so the only devices I've tested were connected over the audio jack.

Did you enable audio for the speakers?

I did not enable speaker support because I also do not really need them or want to risk damaging the speakers.

If you enabled asahi audio do you have any errors or is there anything unusual with your device?

What I have already reported is the only issue I am facing, and again I fortunately found a simple workaround just by invoking sleep.

[life00]

Good news! I am no longer able to reproduce. It was likely fixed.

I also do not see the following error log which was probably related to this issue:

Sep 22 19:20:44 localhost kernel: cs42l83 0-0048: ASoC: error at snd_soc_component_update_bits on cs42l83.0-0048 for register: [0x00001501] -6
Sep 22 19:20:44 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Sep 22 19:20:44 localhost kernel: cs42l83 0-0048: PLL failed to lock: -6

Closing.

[life00]

Weirdly enough it occurred again, and I am not really sure how and why.

I will keep this issue opened because it clearly was not fixed and is still randomly reproducible.

[life00]

This is at least some logs from the issue that I found. Notice cs42l83 like with the previously mentioned errors.

Logs suggest that the following errors happen on wake up after lid is open.

Oct 29 15:53:57 localhost kernel: apple-dcp 231c00000.dcp: dcp_poweroff() done
Oct 29 15:53:57 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Oct 29 15:53:57 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Oct 29 15:53:57 localhost kernel: cs42l83 2-0048: Failed to get PDN_DONE: -6
Oct 29 15:53:57 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Oct 29 15:53:57 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: syslog message: cmd.c:7890: NVMe shutdown start seg->lba: 0, seg->size: 0
Oct 29 15:53:57 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: syslog message: cmd.c:7912: seg->lba 0 saveCtx 1 took 59 ms - clog 5086144
Oct 29 15:53:57 localhost kernel: PM: suspend devices took 1.125 seconds
Oct 29 15:53:57 localhost kernel: macsmc-rtkit 23e400000.smc: RTKit: syslog message: apComms.cpp:375: SMC HID Event: 03 01 00
Oct 29 15:53:57 localhost kernel: macsmc-rtkit 23e400000.smc: RTKit: syslog message: apComms.cpp:375: SMC HID Event: 03 00 01
Oct 29 15:53:57 localhost kernel: macsmc-hid macsmc-hid: Lid wakeup
Oct 29 15:53:57 localhost kernel: cs42l83 2-0048: PLL failed to lock: -16
Oct 29 15:53:57 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: Initializing (protocol version 12)
Oct 29 15:53:57 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: Unknown system endpoint: 0x0a
Oct 29 15:53:57 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: syslog message: cmd.c:6230:  boot mode normal
Oct 29 15:53:57 localhost kernel: i2c-apple 235018000.i2c: Issuing reset due to status 0x08210100 (xfstatus 0x00000000)
Oct 29 15:53:57 localhost kernel: apple-dcp 231c00000.dcp: dcp_poweron() starting

[chadmed]

Please confirm this is fixed with the latest kernel, speakersafetyd and asahi-audio

[life00]

Please confirm this is fixed with the latest kernel, speakersafetyd and asahi-audio

Haven't seen this issue for a while already. I tried various methods and failed to reproduce with 6.6.3-411.asahi.fc39.aarch64+16k kernel, asahi-audio-1.6-1.fc39.src.rpm, and rust-speakersafetyd-0.1.9-1.fc39.src.rpm.

Thanks for fixing. In case it randomly appears again I will reopen the issue and include logs.

[life00]

@chadmed just occurred again right after wake up :cry:

The procedure was similar:

1. have the audio jack plugged in with music playing (maybe it matters?)
2. close the lid and machine goes to sleep
3. take the audio jack out
4. wait for a while and put it back
5. open the lid

Here are all the errors and likely relevant logs after machine wakes up:

...
Dec 29 10:34:54 localhost kernel: cs42l83 2-0048: PLL failed to lock: -16
Dec 29 10:34:54 localhost kernel: nvme-apple 27bcc0000.nvme: RTKit: syslog message: cmd.c:6230:  boot mode normal
Dec 29 10:34:54 localhost kernel: ieee80211 phy0: brcmf_cfg80211_escan_handler: scan not ready, bsscfgidx=0
Dec 29 10:34:54 localhost kernel: ieee80211 phy0: brcmf_fweh_event_worker: event handler failed (69)
Dec 29 10:34:54 localhost kernel: xhci-hcd xhci-hcd.0.auto: xHC error in resume, USBSTS 0x411, Reinit
...
Dec 29 10:34:54 localhost kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:225: bool VideoInterfaceIOAV::open_ioav_gated(): IOAVVideoInterface open failed
...
Dec 29 10:34:54 localhost kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipe.cpp:3456: IOMFB read_pmu_data_sync: pmu ram read error (e00800d8)
...
Dec 29 10:34:54 localhost kernel: snd-soc-macaudio sound: Speaker volumes locked: Main control not locked
Dec 29 10:34:54 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Dec 29 10:34:54 localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Dec 29 10:34:54 localhost speakersafetyd[1564]: WARN  [speakersafetyd] Expected 4096 samples, got 2208
Dec 29 10:34:54 localhost speakersafetyd[1564]: thread 'main' panicked at src/main.rs:314:17:
Dec 29 10:34:54 localhost speakersafetyd[1564]: Invalid sample rate
Dec 29 10:34:54 localhost speakersafetyd[1564]: note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Dec 29 10:34:54 localhost speakersafetyd[1564]: WARN  [speakersafetyd] Panic!
Dec 29 10:34:54 localhost speakersafetyd[1564]: WARN  [speakersafetyd::blackbox] Blackbox is empty, nothing to save
Dec 29 10:34:54 localhost pipewire[2301]: spa.alsa: hw:AppleJ293,0p: (0 suppressed) snd_pcm_avail after recover: Broken pipe
Dec 29 10:34:54 localhost usbguard-daemon[1674]: Ignoring unknown UEvent action: sysfs_devpath=/devices/platform/soc/502280000.usb/xhci-hcd.0.auto/usb1/1-1 action=change
Dec 29 10:34:54 localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=speakersafetyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
...
Dec 29 10:34:54 localhost systemd[1]: speakersafetyd.service: Main process exited, code=exited, status=101/n/a
Dec 29 10:34:54 localhost systemd[1]: speakersafetyd.service: Failed with result 'exit-code'.
...

It is pretty difficult to reproduce.

[life00]

I noticed some more details. This issue is nearly constantly reproducible on a faulty boot. Which means if it is reproducible ones then it will be reproducible multiple times if not rebooting (reminder: there is a temporary fix by putting the device to sleep while having the headphones unplugged). I also noticed that this issue causes brief freezing after the machine wakes up.