Alsa UCM library crashing on Boot

[alosarjos]

Hi there!

I've been redirected here from an issue with Wireplumber crashing on Boot: https://gitlab.freedesktop.org/pipewire/wireplumber/-/work_items/937#note_3417645

The HW:4 is the inboard Audio from a ASUS ROG STRIX B650-A GAMING WIFI Motherboard:

Bus 001 Device 004: ID 0b05:1a52 ASUSTek Computer, Inc. USB Audio

I will put here the info and the crash dump:

Log:

Apr 09 08:10:03 artorias wireplumber[1089]: spa.alsa: can't open control for card hw:4: No existe el fichero o el directorio
Apr 09 08:10:03 artorias systemd-coredump[1421]: [🡕] Process 1089 (wireplumber) of user 965 dumped core.

                                                 Stack trace of thread 1089:
                                                 #0  0x00007efe64faea5d n/a (libasound.so.2 + 0x33a5d)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe64fb3dd5 n/a (libasound.so.2 + 0x38dd5)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe650344c1 snd_use_case_mgr_close (libasound.so.2 + 0xb94c1)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe650b5861 n/a (libspa-alsa.so + 0x1e861)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe690c1aa1 n/a (libpipewire-0.3.so.0 + 0x6caa1)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe690c1ba1 pw_unload_spa_handle (libpipewire-0.3.so.0 + 0x6cba1)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe692f0727 n/a (libwireplumber-0.5.so.0 + 0x17727)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe6929bec0 g_object_unref (libgobject-2.0.so.0 + 0x21ec0)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe69177c48 n/a (libglib-2.0.so.0 + 0x55c48)
                                                 alsa-project/alsa-ucm-conf#9  0x00007efe6917e9a4 n/a (libglib-2.0.so.0 + 0x5c9a4)
                                                 alsa-project/alsa-ucm-conf#10 0x00007efe69181079 n/a (libglib-2.0.so.0 + 0x5f079)
                                                 alsa-project/alsa-ucm-conf#11 0x00007efe69182607 n/a (libglib-2.0.so.0 + 0x60607)
                                                 alsa-project/alsa-ucm-conf#12 0x00007efe691829c7 g_main_loop_run (libglib-2.0.so.0 + 0x609c7)
                                                 alsa-project/alsa-ucm-conf#13 0x000055f1f813151f n/a (/usr/bin/wireplumber + 0x251f)
                                                 alsa-project/alsa-ucm-conf#14 0x00007efe68e5e6c1 n/a (libc.so.6 + 0x276c1)
                                                 alsa-project/alsa-ucm-conf#15 0x00007efe68e5e7f9 __libc_start_main (libc.so.6 + 0x277f9)
                                                 alsa-project/alsa-ucm-conf#16 0x000055f1f8131945 n/a (/usr/bin/wireplumber + 0x2945)

                                                 Stack trace of thread 1096:
                                                 #0  0x00007efe68ed5f32 n/a (libc.so.6 + 0x9ef32)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe68eca39c n/a (libc.so.6 + 0x9339c)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe68eca3e4 n/a (libc.so.6 + 0x933e4)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe68f51595 epoll_wait (libc.so.6 + 0x11a595)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe68893d0a n/a (libspa-support.so + 0x1bd0a)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe6887e63c n/a (libspa-support.so + 0x663c)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe690e0401 n/a (libpipewire-0.3.so.0 + 0x8b401)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1098:
                                                 #0  0x00007efe68f4f06d syscall (libc.so.6 + 0x11806d)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe691aedee g_cond_wait (libglib-2.0.so.0 + 0x8cdee)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe6914822d n/a (libglib-2.0.so.0 + 0x2622d)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe691b89c7 n/a (libglib-2.0.so.0 + 0x969c7)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe691b84fc n/a (libglib-2.0.so.0 + 0x964fc)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1103:
                                                 #0  0x00007efe68ed5f32 n/a (libc.so.6 + 0x9ef32)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe68eca39c n/a (libc.so.6 + 0x9339c)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe68eca3e4 n/a (libc.so.6 + 0x933e4)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe68f51595 epoll_wait (libc.so.6 + 0x11a595)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe68893d0a n/a (libspa-support.so + 0x1bd0a)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe6887e63c n/a (libspa-support.so + 0x663c)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe6907a011 n/a (libpipewire-0.3.so.0 + 0x25011)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1097:
                                                 #0  0x00007efe68ed5f32 n/a (libc.so.6 + 0x9ef32)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe68eca39c n/a (libc.so.6 + 0x9339c)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe68eca3e4 n/a (libc.so.6 + 0x933e4)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe68f442f6 ppoll (libc.so.6 + 0x10d2f6)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe69182734 n/a (libglib-2.0.so.0 + 0x60734)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe69182815 g_main_context_iteration (libglib-2.0.so.0 + 0x60815)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe69182862 n/a (libglib-2.0.so.0 + 0x60862)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe691b84fc n/a (libglib-2.0.so.0 + 0x964fc)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#9  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1099:
                                                 #0  0x00007efe68f4f06d syscall (libc.so.6 + 0x11806d)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe691afbee g_cond_wait_until (libglib-2.0.so.0 + 0x8dbee)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe691481f7 n/a (libglib-2.0.so.0 + 0x261f7)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe6914836f g_async_queue_timeout_pop (libglib-2.0.so.0 + 0x2636f)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe691b9660 n/a (libglib-2.0.so.0 + 0x97660)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe691b84fc n/a (libglib-2.0.so.0 + 0x964fc)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1111:
                                                 #0  0x00007efe68ed5f32 n/a (libc.so.6 + 0x9ef32)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe68eca39c n/a (libc.so.6 + 0x9339c)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe68eca3e4 n/a (libc.so.6 + 0x933e4)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe68f442f6 ppoll (libc.so.6 + 0x10d2f6)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe4dc2e36c _ZN9libcamera19EventDispatcherPoll4pollEPSt6vectorI6pollfdSaIS2_EE (libcamera-base.so.0.7 + 0x1a36c)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe4dc2ed8b _ZN9libcamera19EventDispatcherPoll13processEventsEv (libcamera-base.so.0.7 + 0x1ad8b)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe4dc27679 _ZN9libcamera6Thread4execEv (libcamera-base.so.0.7 + 0x13679)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe4d542376 _ZN9libcamera13CameraManager7Private3runEv (libcamera.so.0.7 + 0xa2376)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe422e55a4 n/a (libstdc++.so.6 + 0xe55a4)
                                                 alsa-project/alsa-ucm-conf#9  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#10 0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)

                                                 Stack trace of thread 1100:
                                                 #0  0x00007efe68ed5f32 n/a (libc.so.6 + 0x9ef32)
                                                 alsa-project/alsa-ucm-conf#1  0x00007efe68eca39c n/a (libc.so.6 + 0x9339c)
                                                 alsa-project/alsa-ucm-conf#2  0x00007efe68eca3e4 n/a (libc.so.6 + 0x933e4)
                                                 alsa-project/alsa-ucm-conf#3  0x00007efe68f442f6 ppoll (libc.so.6 + 0x10d2f6)
                                                 alsa-project/alsa-ucm-conf#4  0x00007efe69182734 n/a (libglib-2.0.so.0 + 0x60734)
                                                 alsa-project/alsa-ucm-conf#5  0x00007efe691829c7 g_main_loop_run (libglib-2.0.so.0 + 0x609c7)
                                                 alsa-project/alsa-ucm-conf#6  0x00007efe68d746a4 n/a (libgio-2.0.so.0 + 0x1196a4)
                                                 alsa-project/alsa-ucm-conf#7  0x00007efe691b84fc n/a (libglib-2.0.so.0 + 0x964fc)
                                                 alsa-project/alsa-ucm-conf#8  0x00007efe68ecd97a n/a (libc.so.6 + 0x9697a)
                                                 alsa-project/alsa-ucm-conf#9  0x00007efe68f512bc n/a (libc.so.6 + 0x11a2bc)
                                                 ELF object binary architecture: AMD x86-64

The backtrace:

#0  0x00007efe64faea5d in uc_mgr_free_dev_list (dev_list=0x55f21b6e4e78) at ucm/utils.c:435
alsa-project/alsa-ucm-conf#1  uc_mgr_free_device (dev=0x55f21b6e4e10) at ucm/utils.c:613
alsa-project/alsa-ucm-conf#2  0x00007efe64fb3dd5 in uc_mgr_free_device_list (base=0x55f21b642208) at ucm/utils.c:626
alsa-project/alsa-ucm-conf#3  uc_mgr_free_verb (uc_mgr=uc_mgr@entry=0x55f21b535d50) at ucm/utils.c:799
alsa-project/alsa-ucm-conf#4  0x00007efe650344c1 in uc_mgr_free (uc_mgr=0x55f21b535d50) at ucm/utils.c:826
alsa-project/alsa-ucm-conf#5  snd_use_case_mgr_close (uc_mgr=0x55f21b535d50) at ucm/main.c:1901
alsa-project/alsa-ucm-conf#6  0x00007efe650b5861 in pa_alsa_ucm_free (ucm=0x55f21b656b40) at ../pipewire/spa/plugins/alsa/acp/alsa-ucm.c:2749
alsa-project/alsa-ucm-conf#7  acp_card_destroy (card=0x55f21b656ac0) at ../pipewire/spa/plugins/alsa/acp/acp.c:2089
alsa-project/alsa-ucm-conf#8  impl_clear (handle=0x55f21b6565b8) at ../pipewire/spa/plugins/alsa/alsa-acp-device.c:1116
alsa-project/alsa-ucm-conf#9  0x00007efe690c1aa1 in spa_handle_clear (object=0x55f21b6565b8) at ../pipewire/spa/include/spa/support/plugin.h:72
alsa-project/alsa-ucm-conf#10 unref_handle (handle=0x55f21b656590) at ../pipewire/src/pipewire/pipewire.c:196
alsa-project/alsa-ucm-conf#11 0x00007efe690c1ba1 in unref_handle (handle=<optimized out>) at ../pipewire/src/pipewire/pipewire.c:192
alsa-project/alsa-ucm-conf#12 pw_unload_spa_handle (handle=0x55f21b6565b8) at ../pipewire/src/pipewire/pipewire.c:329
alsa-project/alsa-ucm-conf#13 0x00007efe692f0727 in wp_spa_device_finalize (object=0x55f21b755390) at ../wireplumber/lib/wp/device.c:271
alsa-project/alsa-ucm-conf#14 0x00007efe6929bec0 in g_object_unref (_object=0x55f21b755390) at ../glib/gobject/gobject.c:4910
alsa-project/alsa-ucm-conf#15 0x00007efe69177c48 in g_source_callback_unref (cb_data=0x55f21b793950) at ../glib/glib/gmain.c:1759
alsa-project/alsa-ucm-conf#16 g_source_callback_unref (cb_data=0x55f21b793950) at ../glib/glib/gmain.c:1752
alsa-project/alsa-ucm-conf#17 0x00007efe6917e9a4 in g_source_destroy_internal (source=0x55f21b708680, context=0x55f21b44bfd0, have_lock=1) at ../glib/glib/gmain.c:1354
alsa-project/alsa-ucm-conf#18 0x00007efe69181079 in g_main_dispatch (context=0x55f21b44bfd0) at ../glib/glib/gmain.c:3621
alsa-project/alsa-ucm-conf#19 0x00007efe69182607 in g_main_context_dispatch_unlocked (context=0x55f21b44bfd0) at ../glib/glib/gmain.c:4451
alsa-project/alsa-ucm-conf#20 g_main_context_iterate_unlocked (context=0x55f21b44bfd0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4516
alsa-project/alsa-ucm-conf#21 0x00007efe691829c7 in g_main_loop_run (loop=0x55f21b44bf90) at ../glib/glib/gmain.c:4721
alsa-project/alsa-ucm-conf#22 0x000055f1f813151f in main (argc=<optimized out>, argv=<optimized out>) at ../wireplumber/src/main.c:255

Pipewire sink info:

Sink alsa-project/alsa-ucm-conf#69
        State: IDLE
        Name: alsa_output.usb-Generic_USB_Audio-00.HiFi__Speaker__sink
        Description: Edifier M60
        Driver: PipeWire
        Sample Specification: s32le 2ch 48000Hz
        Channel Map: front-left,front-right
        Owner Module: 4294967295
        Mute: no
        Volume: front-left: 26214 /  40% / -23,88 dB,   front-right: 26214 /  40% / -23,88 dB
                balance 0,00
        Base Volume: 65536 / 100% / 0,00 dB
        Monitor Source: alsa_output.usb-Generic_USB_Audio-00.HiFi__Speaker__sink.monitor
        Latency: 0 usec, configured 0 usec
        Flags: HARDWARE HW_MUTE_CTRL HW_VOLUME_CTRL DECIBEL_VOLUME LATENCY
        Properties:
                object.path = "alsa:acp:Audio:11:playback"
                api.alsa.path = "hw:Audio"
                api.alsa.open.ucm = "true"
                api.alsa.pcm.card = "4"
                api.alsa.pcm.stream = "playback"
                port.group = "playback"
                device.icon_name = "audio-speakers"
                device.bus = "usb"
                audio.channels = "2"
                audio.position = "[ FL, FR ]"
                device.routes = "1"
                alsa.mixer_device = "_ucm0004.hw:Audio"
                alsa.resolution_bits = "16"
                alsa.card = "4"
                alsa.card_name = "Edifier M60"
                alsa.long_card_name = "Edifier M60"
                alsa.driver_name = "snd_usb_audio"
                alsa.mixer_name = "USB Mixer"
                alsa.components = "USB0b05:1a52"
                alsa.id = "Audio"
                device.api = "alsa"
                device.class = "sound"
                alsa.class = "generic"
                alsa.subclass = "generic-mix"
                alsa.name = "USB Audio"
                alsa.subdevice = "0"
                alsa.subdevice_name = "subdevice #0"
                alsa.device = "0"
                alsa.sync.id = "00000000:00000000:00000000:00000000"
                device.profile.name = "HiFi: Speaker: sink"
                device.profile.description = "Speakers"
                card.profile.device = "11"
                device.id = "50"
                factory.name = "api.alsa.pcm.sink"
                node.pause-on-idle = "false"
                priority.driver = "1100"
                priority.session = "1100"
                media.class = "Audio/Sink"
                node.name = "alsa_output.usb-Generic_USB_Audio-00.HiFi__Speaker__sink"
                node.nick = "Edifier M60"
                device.description = "Edifier M60"
                api.alsa.card.name = "USB Audio"
                api.alsa.card.longname = "Generic USB Audio at usb-0000:0c:00.0-6, high speed"
                device.name = "Edifier M60"
                session.suspend-timeout-seconds = "0"
                factory.id = "19"
                clock.quantum-limit = "8192"
                client.id = "41"
                node.driver = "true"
                node.loop.name = "data-loop.0"
                library.name = "audioconvert/libspa-audioconvert"
                object.id = "68"
                object.serial = "69"
                node.max-latency = "16384/48000"
                api.alsa.period-size = "512"
                api.alsa.period-num = "64"
                api.alsa.headroom = "512"
                device.enum.api = "udev"
                api.alsa.card = "4"
                device.plugged.usec = "15803626"
                device.bus_path = "pci-0000:0c:00.0-usb-0:6:1.0"
                sysfs.path = "/devices/pci0000:00/0000:00:02.1/0000:05:00.0/0000:06:0c.0/0000:0c:00.0/usb1/1-6/1-6:1.0/sound/card4"
                device.bus-id = "usb-Generic_USB_Audio-00"
                device.subsystem = "sound"
                device.vendor.id = "0x0b05"
                device.vendor.name = "ASUSTek Computer, Inc."
                device.product.id = "0x1a52"
                device.product.name = "USB Audio"
                device.serial = "Generic_USB_Audio"
                device.nick = "USB Audio"
                api.alsa.use-acp = "true"
                api.acp.auto-profile = "false"
                api.acp.auto-port = "false"
                api.dbus.ReserveDevice1.Priority = "-20"
                api.alsa.split-enable = "true"
                api.dbus.ReserveDevice1 = "Audio4"
                spa.object.id = "10"
                device.string = "4"
        Ports:
                [Out] Speaker: Speakers (type: Speaker, priority: 200, availability group: Speaker - Output, available)
        Active Port: [Out] Speaker
        Formats:
                pcm

[perexg]

It's alsa-lib issue. Could you attach (don't paste) output from alsa-info.sh --no-upload and also output from alsaucm -c hw:4 dump text ? Thank you

[alosarjos]

alsa-info.txt

After reboot, it was the hw:3 (Still same crash error)

alsaucm.txt

[perexg]

So it's ALC4080 hardware. I guess that alsaucm command does not trigger the crash, right? It this problem visible only on boot? Or it persists, if you restart wireplumber ?

Could you attach valgrind check for alsaucm (valgrind --leak-check=yes --show-reachable=yes alsaucm -c hw:Audio dump text) ?

[alosarjos]

Running the aslaucm did not trigger any crash on the system

Restarting wireplumber also is not triggering the crash

I'm a bit confused, because it happens on boot only, and before login in, it's the plasmalogin user running wireplumber before that.

Maybe some race condition on boot?

valg.txt

[alosarjos]

I've been doing some tests, I'm not sure what this means but.

There is a DAC for a Wireless Headset I have, the USB-Audio - Arctis Pro Wireless. Completely different Audio Output connected through a USB to the PC.

IF this is disconnected during boot, there is no alsa-lib crash.

Connecting it after login in, no crash neither.

The alsaucm commands fails for this device, saying it is not supported.

[perexg]

Could you try to mask wireplumber service and start it manually to see, if the crash can be triggered when you start wireplumber manually ?

Also, please attach alsactl dump-cfg output when the external card is connected at boot.

[alosarjos]

This is the dump-cfg for a sesssion with it crashing on boot

alsadump.txt

I'm not sure on the first thing, since it's crashing when wireplumber is started by plasmalogin, not my user when login in. So it's neither systemctl mask or systemctl --user mask

[alosarjos]

Best I could think is, I disabled the plasmalogin service. Rebooted (Into a tty) checked that wireplumber service was running and no crashes.

Reenabled the service, rebooted, entered KDE Plasma and crashes are back.

[alosarjos]

Masked the service for plasma-login-manager and no errors and everything seems to work. There are 0 errors when using Wireplumber as my user, only when triggered by plasma-login-manager.

I'm yet not sure if it's a report for them or here since the lib crashing is alsa.

[perexg]

It's also suspicious that wireplumber cannot open the onboard USB card device (it's not standard):

spa.alsa: can't open control for card hw:4: No existe el fichero o el directorio

Then there is crash when pipewire wants to clean UCM handle. So the memory may be corrupted outside UCM code. But it's just a wild guess. I am a bit out of ideas, how to debug this outside standard user session. Perhaps, you may check the device permissions in /dev/snd/ directory. But it also may be a runtime thing (udev may create those devices a bit later than plasma-login-manager starts).

[alosarjos]

Got some more news from testing.

I tested disabling plasmalogin, rebooting, going into a TTY and starting plasmalogin service manually, no crashes.

So, I edited the plasmalogin service and added:

ExecStartPre=/usr/bin/sleep 3

And no more crashes. If I set the sleep to lower than that, crashes come back, so it looks like a race condition.

So maybe the issue is that the service needs some After or some rule so it waits to audio system to be completely ready?