M1 Pro headphone audio fails on boot 80% of the time

[AmateurECE]

asahi-gentoosupport-issue-39-kernel-config.txt Model: Apple MacBook Pro (14-inch, M1 Pro, 2021) DTS Compatible String: "apple,j314s", "apple,t6000", "apple,arm-platform" Kernel: Linux hackbook 6.4.0-asahi-9-edge-ARCH #1 SMP PREEMPT_DYNAMIC Thu Aug 24 06:21:26 CDT 2023 aarch64 GNU/Linux

Hello! We might end up turning around and creating an issue in AsahiLinux/linux, but I figured I'd start here. Since June or so, headphone audio on my M1 Pro MacBook only works about 20% of the time on boot. When it doesn't work, I see this:

[    3.483820] ALSA pcmC0D0p,0:: cannot preallocate for size 3145728
[    3.484256] ALSA pcmC0D0c,0:: cannot preallocate for size 3145728
[    3.484891] ALSA pcmC0D1p,0:: cannot preallocate for size 3145728
[    3.485173] snd-soc-macaudio sound: adding routes for 'mca-i2s-2'
[    3.487245] input: MacBook Pro J314 Headphone Jack as /devices/platform/sound/sound/card0/input5

And speaker-test shows this:

speaker-test 1.2.9

Playback device is default
Stream parameters are 48000Hz, S16_LE, 1 channels
Using 16 octaves of pink noise
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 256 to 206158430
Period size range from 128 to 32768
Using max buffer size 206158428
Periods = 4
Unable to set hw params for playback: Cannot allocate memory
Setting of hwparams failed: Cannot allocate memory

When I rmmod snd-soc-macaudio snd-soc-apple-mca apple_admac, The kernel emits a warning:

[ 7185.890505] ------------[ cut here ]------------
[ 7185.890509] WARNING: CPU: 5 PID: 24802 at drivers/iommu/iommu.c:3079 iommu_device_
unuse_default_domain+0x48/0x6c
[ 7185.890515] Modules linked in: snd_seq_dummy snd_hrtimer snd_seq snd_seq_device br
cmfmac_wcc des_generic libdes md4 8021q mrp garp stp llc hci_bcm4377 bluetooth ecdh_g
eneric brcmfmac ecc brcmutil appledrm ofpart asahi spi_nor snd_soc_cs42l84 snd_soc_ta
s2764 pwm_apple apple_dcp macsmc_hid drm_dma_helper cfg80211 rfkill joydev apple_soc_
cpufreq leds_pwm loop fuse sdhci_pci cqhci sdhci mmc_core hid_magicmouse hid_apple nv
mem_spmi_mfd spi_hid_apple_of tps6598x spi_hid_apple macsmc_reboot simple_mfd_spmi gp
io_macsmc macsmc_power rtc_macsmc regmap_spmi dwc3 pcie_apple udc_core pci_host_commo
n phy_apple_atc typec spi_apple apple_admac(-) i2c_apple apple_dart nvmem_apple_efuse
s macsmc_rtkit macsmc mfd_core spmi_apple_controller pinctrl_apple_gpio clk_apple_nco
 btrfs raid6_pq xor xor_neon nvme_apple apple_sart [last unloaded: snd_soc_apple_mca]
[ 7185.890543] CPU: 5 PID: 24802 Comm: rmmod Tainted: G S                 6.4.0-asahi
-9-edge-ARCH #1
[ 7185.890544] Hardware name: Apple MacBook Pro (14-inch, M1 Pro, 2021) (DT)
[ 7185.890545] pstate: 81400009 (Nzcv daif +PAN -UAO -TCO +DIT -SSBS BTYPE=--)
[ 7185.890547] pc : iommu_device_unuse_default_domain+0x48/0x6c
[ 7185.890549] lr : iommu_device_unuse_default_domain+0x2c/0x6c
[ 7185.890550] sp : ffff800015d4bca0
[ 7185.890551] x29: ffff800015d4bca0 x28: ffff000014209b00 x27: 0000000000000000
[ 7185.890553] x26: 0000000000000000 x25: 0000000000000000 x24: 0000000000000000
[ 7185.890554] x23: ffff00000c390c90 x22: ffff800000f48068 x21: ffff00000c395c90
[ 7185.890555] x20: ffff0000112ebd00 x19: ffff0000112ebd68 x18: ffff800008bef480
[ 7185.890557] x17: 0000000000000000 x16: 0000000000000076 x15: 0000000003a57226
[ 7185.890558] x14: 000000000000024d x13: 0000000000000076 x12: 000000000198ace3
[ 7185.890559] x11: 0000000000000001 x10: ffff0003ce982b40 x9 : 0000000000000000
[ 7185.890560] x8 : 0000000000000000 x7 : 7f7f7f7f7f7f7f7f x6 : 72656c6c6f72746e
[ 7185.890562] x5 : 0000000000000001 x4 : 0000068918735ca9 x3 : 0000000000000004
[ 7185.890563] x2 : 0000000000000000 x1 : 00000000000000c0 x0 : 0000000000000000
[ 7185.890564] Call trace:
[ 7185.890564]  iommu_device_unuse_default_domain+0x48/0x6c
[ 7185.890566]  platform_dma_cleanup+0x1c/0x28
[ 7185.890569]  device_release_driver_internal+0x1ac/0x260
[ 7185.890571]  driver_detach+0x90/0xd0
[ 7185.890572]  bus_remove_driver+0xe0/0x150
[ 7185.890573]  driver_unregister+0x30/0x54
[ 7185.890575]  platform_driver_unregister+0x14/0x20
[ 7185.890577]  cleanup_module+0x18/0x26a0 [apple_admac]
[ 7185.890582]  __arm64_sys_delete_module+0x21c/0x380
[ 7185.890585]  invoke_syscall+0x48/0xe0
[ 7185.890588]  do_el0_svc+0x94/0x124
[ 7185.890589]  el0_svc+0x30/0x108
[ 7185.890593]  el0t_64_sync_handler+0x84/0xf0
[ 7185.890594]  el0t_64_sync+0x190/0x194
[ 7185.890595] ---[ end trace 0000000000000000 ]---

When I modprobe those three modules again, I get the output that I expect in dmesg:

...
[ 8052.372878]  Secondary: ASoC: error at snd_soc_link_hw_params on Secondary: -22
[ 8052.372879]  Secondary: ASoC: error at __soc_pcm_hw_params on Secondary: -22
[ 8052.372879]  Secondary: ASoC: error at dpcm_fe_dai_hw_params on Secondary: -22
[ 8052.372906]  Secondary: opening PCM device 'Secondary' with no audio route configured (bad settings applied to the sound card)
...

And speaker-test appears to actually be streaming audio to the sound card, but...still no sound, so this is unfortunately not a valid workaround. I poked around in the kernel a little bit, and this feels kind of like a resource leak in one of the consumers of the apple_admac driver. Unfortunately, I don't know enough about this platform to be of any greater service. My kernel config is attached. Thanks for taking a look!

[chadmed]

This is a known issue but seems to be difficult to reproduce. @povik might have some more info but it's very flaky.

As for the errors in dmesg about the audio routes, you need to go into alsamixer and set the Speakers DAI to "Secondary"

[AmateurECE]

I see! Thanks for the alsamixer tip, I would not have figured that out otherwise. At any rate, I seem to have no trouble reproducing it, so if there's any diagnostics I can grab or testing I can do to help resolve this issue, don't hesitate to let me know :smile: