Pulseaudio gets stuck and wont die

Smit · 2022-02-12 05:14:02

This started happening after update yesterday. (major update was KDE 5.24)

When I boot my laptop. there is not sound. pulseaudio shows up in process list but I can't kill it(so I can restart it) even with -9.
I disabled its socket and then on tty manually started the pulseaudio and it gets stuck at `D: [pulseaudio] module-udev-detect.c: Loading module-alsa-card with arguments`
Ctrl+C does not work. sending kill from other tty also does not work.

❯ pulseaudio -vvv    
I: [pulseaudio] main.c: setrlimit(RLIMIT_RTPRIO, (9, 9)) failed: Operation not permitted
D: [pulseaudio] core-rtclock.c: Timer slack is set to 50 us.
D: [pulseaudio] core-util.c: setpriority() worked.
I: [pulseaudio] core-util.c: Successfully gained nice level -11.
I: [pulseaudio] main.c: This is PulseAudio 15.0
D: [pulseaudio] main.c: Compilation CFLAGS: Not yet supported on meson
D: [pulseaudio] main.c: Running on host: Linux x86_64 5.16.8-zen1-1-zen #1 ZEN SMP PREEMPT Tue, 08 Feb 2022 21:21:15 +0000
D: [pulseaudio] main.c: Found 8 CPUs.
I: [pulseaudio] main.c: Page size is 4096 bytes
D: [pulseaudio] main.c: Compiled with Valgrind support: yes
D: [pulseaudio] main.c: Running in valgrind mode: no
D: [pulseaudio] main.c: Running in VM: no
D: [pulseaudio] main.c: Running from build tree: no
D: [pulseaudio] main.c: Optimized build: yes
D: [pulseaudio] main.c: All asserts enabled.
I: [pulseaudio] main.c: Machine ID is d40099a80c6f496f9e599808bf7d7ae8.
I: [pulseaudio] main.c: Session ID is 3.
I: [pulseaudio] main.c: Using runtime directory /run/user/1000/pulse.
I: [pulseaudio] main.c: Using state directory /home/smit/.config/pulse.
I: [pulseaudio] main.c: Using modules directory /usr/lib/pulse-15.0/modules.
I: [pulseaudio] main.c: Running in system mode: no
I: [pulseaudio] main.c: System supports high resolution timers
D: [pulseaudio] memblock.c: Using shared memfd memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65472
I: [pulseaudio] cpu-x86.c: CPU flags: CMOV MMX SSE SSE2 SSE3 SSSE3 SSE4_1 SSE4_2 
I: [pulseaudio] svolume_mmx.c: Initialising MMX optimized volume functions.
I: [pulseaudio] remap_mmx.c: Initialising MMX optimized remappers.
I: [pulseaudio] svolume_sse.c: Initialising SSE2 optimized volume functions.
I: [pulseaudio] remap_sse.c: Initialising SSE2 optimized remappers.
I: [pulseaudio] sconv_sse.c: Initialising SSE2 optimized conversions.
I: [pulseaudio] svolume_orc.c: Initialising ORC optimized volume functions.
D: [pulseaudio] database-tdb.c: Opened TDB database '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-device-volumes.tdb'
I: [pulseaudio] database.c: Successfully opened 'device-volumes' database file '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-device-volumes.tdb'.
I: [pulseaudio] module.c: Loaded "module-device-restore" (index: #0; argument: "").
D: [pulseaudio] database-tdb.c: Opened TDB database '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-stream-volumes.tdb'
I: [pulseaudio] database.c: Successfully opened 'stream-volumes' database file '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-stream-volumes.tdb'.
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1 added for object /org/pulseaudio/stream_restore1
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry0
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry1
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry2
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry3
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry4
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry5
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry6
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry7
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry8
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry9
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry10
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry11
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry12
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Ext.StreamRestore1.RestoreEntry added for object /org/pulseaudio/stream_restore1/entry13
I: [pulseaudio] module.c: Loaded "module-stream-restore" (index: #1; argument: "").
D: [pulseaudio] database-tdb.c: Opened TDB database '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-card-database.tdb'
I: [pulseaudio] database.c: Successfully opened 'card-database' database file '/home/smit/.config/pulse/d40099a80c6f496f9e599808bf7d7ae8-card-database.tdb'.
I: [pulseaudio] module.c: Loaded "module-card-restore" (index: #2; argument: "").
I: [pulseaudio] module.c: Loaded "module-augment-properties" (index: #3; argument: "").
I: [pulseaudio] module.c: Loaded "module-switch-on-port-available" (index: #4; argument: "").
D: [pulseaudio] module.c: Checking for existence of '/usr/lib/pulse-15.0/modules/module-udev-detect.so': success
D: [pulseaudio] module-udev-detect.c: /dev/snd/controlC0 is accessible: yes
D: [pulseaudio] module-udev-detect.c: /devices/pci0000:00/0000:00:1f.3/sound/card0 is busy: no
D: [pulseaudio] module-udev-detect.c: Loading module-alsa-card with arguments 'device_id="0" name="pci-0000_00_1f.3" card_name="alsa_card.pci-0000_00_1f.3" namereg_fail=false tsched=yes fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1"'

I tried creating fresh new user and same happens

I also see someting related to pulse in dmesg

[  369.761966]  </TASK>
[  369.761969] INFO: task pulseaudio:888 blocked for more than 245 seconds.
[  369.761971]       Tainted: G     U     OE     5.16.8-zen1-1-zen #1
[  369.761973] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  369.761973] task:pulseaudio      state:D stack:    0 pid:  888 ppid:     1 flags:0x00000004
[  369.761976] Call Trace:
[  369.761977]  <TASK>
[  369.761978]  __schedule+0x9e7/0x1110
[  369.761982]  ? __alloc_pages+0x1e1/0x1160
[  369.761985]  schedule+0x4b/0xc0
[  369.761989]  rwsem_down_write_slowpath+0x1df/0x640
[  369.761992]  snd_ctl_release+0x89/0x1c0 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  369.762002]  __fput+0x9a/0x250
[  369.762005]  task_work_run+0x5c/0x90
[  369.762008]  exit_to_user_mode_prepare+0x168/0x170
[  369.762012]  syscall_exit_to_user_mode+0x23/0x40
[  369.762015]  do_syscall_64+0x69/0x80
[  369.762018]  ? syscall_exit_to_user_mode+0x23/0x40
[  369.762020]  ? do_syscall_64+0x69/0x80
[  369.762023]  ? do_user_addr_fault+0x1e4/0x6d0
[  369.762026]  ? exc_page_fault+0x72/0x170
[  369.762028]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  369.762031] RIP: 0033:0x7f97e9405fe7
[  369.762033] RSP: 002b:00007ffe4a75a198 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
[  369.762034] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f97e9405fe7
[  369.762036] RDX: 00007ffe4a75a1a0 RSI: 0000000081785501 RDI: 000000000000000f
[  369.762037] RBP: 000000000000000f R08: 0000000000000000 R09: 00007ffe4a75a0d7
[  369.762038] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f97e46dd960
[  369.762039] R13: 00005566280d6130 R14: 00005566280d5f10 R15: 0000000000000000
[  369.762041]  </TASK>
[  369.762090] INFO: task pulseaudio:2449 blocked for more than 122 seconds.
[  369.762092]       Tainted: G     U     OE     5.16.8-zen1-1-zen #1
[  369.762093] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  369.762094] task:pulseaudio      state:D stack:    0 pid: 2449 ppid:  2408 flags:0x00000000
[  369.762097] Call Trace:
[  369.762097]  <TASK>
[  369.762099]  __schedule+0x9e7/0x1110
[  369.762103]  schedule+0x4b/0xc0
[  369.762106]  rwsem_down_write_slowpath+0x1df/0x640
[  369.762109]  snd_ctl_release+0x89/0x1c0 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  369.762118]  __fput+0x9a/0x250
[  369.762121]  task_work_run+0x5c/0x90
[  369.762123]  exit_to_user_mode_prepare+0x168/0x170
[  369.762127]  syscall_exit_to_user_mode+0x23/0x40
[  369.762129]  do_syscall_64+0x69/0x80
[  369.762132]  ? syscall_exit_to_user_mode+0x23/0x40
[  369.762135]  ? do_syscall_64+0x69/0x80
[  369.762137]  ? exc_page_fault+0x72/0x170
[  369.762140]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  369.762142] RIP: 0033:0x7fd94d9bffe7
[  369.762144] RSP: 002b:00007ffc03c079e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
[  369.762145] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fd94d9bffe7
[  369.762146] RDX: 00007ffc03c079f0 RSI: 0000000081785501 RDI: 000000000000000e
[  369.762147] RBP: 000000000000000e R08: 0000000000000000 R09: 00007ffc03c07927
[  369.762148] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fd948c97960
[  369.762149] R13: 0000558ce92c3790 R14: 0000558ce92bb4f0 R15: 0000000000000000
[  369.762152]  </TASK>
[  492.639441] INFO: task kworker/4:1:83 blocked for more than 368 seconds.
[  492.639459]       Tainted: G     U     OE     5.16.8-zen1-1-zen #1
[  492.639465] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.639469] task:kworker/4:1     state:D stack:    0 pid:   83 ppid:     2 flags:0x00004000
[  492.639483] Workqueue: pm pm_runtime_work
[  492.639501] Call Trace:
[  492.639504]  <TASK>
[  492.639511]  __schedule+0x9e7/0x1110
[  492.639533]  schedule_preempt_disabled+0x52/0xd0
[  492.639546]  __mutex_lock.constprop.0+0x258/0x590
[  492.639555]  ? init_timer_key+0x90/0x90
[  492.639572]  alc256_init+0x7c/0x720 [snd_hda_codec_realtek 6ba348d586c424765439c8aa4eace8b6a76f77e7]
[  492.639609]  alc_init+0x4e/0x490 [snd_hda_codec_realtek 6ba348d586c424765439c8aa4eace8b6a76f77e7]
[  492.639640]  alc269_resume+0x33/0x2f0 [snd_hda_codec_realtek 6ba348d586c424765439c8aa4eace8b6a76f77e7]
[  492.639668]  hda_call_codec_resume+0xee/0x190 [snd_hda_codec 58e9ae5920dd552f1398c8b427e6dcd051068c3f]
[  492.639710]  ? hda_call_codec_resume+0x190/0x190 [snd_hda_codec 58e9ae5920dd552f1398c8b427e6dcd051068c3f]
[  492.639746]  hda_codec_runtime_resume+0x2c/0x60 [snd_hda_codec 58e9ae5920dd552f1398c8b427e6dcd051068c3f]
[  492.639780]  __rpm_callback+0x44/0x160
[  492.639790]  ? hda_call_codec_resume+0x190/0x190 [snd_hda_codec 58e9ae5920dd552f1398c8b427e6dcd051068c3f]
[  492.639824]  rpm_resume+0x703/0x940
[  492.639837]  pm_runtime_work+0x6c/0xa0
[  492.639847]  process_one_work+0x253/0x440
[  492.639868]  worker_thread+0x54/0x4d0
[  492.639875]  ? rescuer_thread+0x5b0/0x5b0
[  492.639882]  kthread+0x1e3/0x210
[  492.639892]  ? kthread_unuse_mm+0xa0/0xa0
[  492.639902]  ret_from_fork+0x22/0x30
[  492.639918]  </TASK>
[  492.639952] INFO: task alsactl:723 blocked for more than 368 seconds.
[  492.639960]       Tainted: G     U     OE     5.16.8-zen1-1-zen #1
[  492.639964] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.639968] task:alsactl         state:D stack:    0 pid:  723 ppid:     1 flags:0x00004000
[  492.639977] Call Trace:
[  492.639980]  <TASK>
[  492.639983]  __schedule+0x9e7/0x1110
[  492.639996]  ? __pm_runtime_idle+0x51/0x100
[  492.640005]  ? rpm_resume+0x228/0x940
[  492.640014]  schedule+0x4b/0xc0
[  492.640025]  rpm_resume+0x1a8/0x940
[  492.640033]  ? finish_wait+0x80/0x80
[  492.640043]  __pm_runtime_resume+0x4a/0x80
[  492.640052]  codec_exec_verb+0x49/0x170 [snd_hda_codec 58e9ae5920dd552f1398c8b427e6dcd051068c3f]
[  492.640088]  alc_process_coef_fw+0xc9/0xf0 [snd_hda_codec_realtek 6ba348d586c424765439c8aa4eace8b6a76f77e7]
[  492.640118]  alc_update_headset_mode+0x1577/0x1d70 [snd_hda_codec_realtek 6ba348d586c424765439c8aa4eace8b6a76f77e7]
[  492.640151]  mux_enum_put+0xf8/0x200 [snd_hda_codec_generic d84959950e3b150810ca021afc04f515dc323c8b]
[  492.640272]  snd_ctl_elem_write+0x118/0x270 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  492.640333]  ? snd_ctl_ioctl+0x100/0x940 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  492.640358]  ? __kmalloc_track_caller+0x190/0x340
[  492.640368]  ? __check_object_size+0x136/0x150
[  492.640378]  ? _copy_from_user+0x28/0x60
[  492.640390]  snd_ctl_ioctl+0x11e/0x940 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  492.640413]  ? syscall_exit_to_user_mode+0x23/0x40
[  492.640421]  ? do_syscall_64+0x69/0x80
[  492.640432]  __x64_sys_ioctl+0x82/0xb0
[  492.640445]  do_syscall_64+0x5c/0x80
[  492.640454]  ? syscall_exit_to_user_mode+0x23/0x40
[  492.640461]  ? do_syscall_64+0x69/0x80
[  492.640469]  ? do_syscall_64+0x69/0x80
[  492.640477]  ? do_syscall_64+0x69/0x80
[  492.640485]  ? do_syscall_64+0x69/0x80
[  492.640493]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  492.640505] RIP: 0033:0x7f41bd4eb59b
[  492.640514] RSP: 002b:00007ffeb3b32dd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  492.640524] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f41bd4eb59b
[  492.640530] RDX: 00007ffeb3b32f10 RSI: 00000000c4c85513 RDI: 0000000000000003
[  492.640537] RBP: 00007ffeb3b334b0 R08: 0000000000000001 R09: 0000557a2c6d8cda
[  492.640542] R10: 00007f41bd553e10 R11: 0000000000000246 R12: 0000000000000006
[  492.640547] R13: 0000000000000001 R14: 0000000000000003 R15: 00007ffeb3b32e00
[  492.640558]  </TASK>
[  492.640568] INFO: task pulseaudio:888 blocked for more than 368 seconds.
[  492.640578]       Tainted: G     U     OE     5.16.8-zen1-1-zen #1
[  492.640584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.640588] task:pulseaudio      state:D stack:    0 pid:  888 ppid:     1 flags:0x00000004
[  492.640599] Call Trace:
[  492.640602]  <TASK>
[  492.640606]  __schedule+0x9e7/0x1110
[  492.640620]  ? __alloc_pages+0x1e1/0x1160
[  492.640629]  schedule+0x4b/0xc0
[  492.640639]  rwsem_down_write_slowpath+0x1df/0x640
[  492.640650]  snd_ctl_release+0x89/0x1c0 [snd e30d25464e5e29a71d61ddac133478f41b51d93f]
[  492.640679]  __fput+0x9a/0x250
[  492.640691]  task_work_run+0x5c/0x90
[  492.640700]  exit_to_user_mode_prepare+0x168/0x170
[  492.640712]  syscall_exit_to_user_mode+0x23/0x40
[  492.640719]  do_syscall_64+0x69/0x80
[  492.640730]  ? syscall_exit_to_user_mode+0x23/0x40
[  492.640736]  ? do_syscall_64+0x69/0x80
[  492.640744]  ? do_user_addr_fault+0x1e4/0x6d0
[  492.640751]  ? exc_page_fault+0x72/0x170
[  492.640758]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  492.640766] RIP: 0033:0x7f97e9405fe7
[  492.640770] RSP: 002b:00007ffe4a75a198 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
[  492.640776] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f97e9405fe7
[  492.640779] RDX: 00007ffe4a75a1a0 RSI: 0000000081785501 RDI: 000000000000000f
[  492.640782] RBP: 000000000000000f R08: 0000000000000000 R09: 00007ffe4a75a0d7
[  492.640785] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f97e46dd960
[  492.640789] R13: 00005566280d6130 R14: 00005566280d5f10 R15: 0000000000000000
[  492.640795]  </TASK>

When I try to shutdown I get stuck waiting for

a stop job is running for save/restore sound card state

and wait time keeps increasing until I have hold down power button to force shutdown my laptop

Last edited by Smit (2022-02-12 05:27:57)

V1del · 2022-02-12 14:01:05

There's a general problem accessing your audio device that hs nothing to do with pulseaudio per se. If the update included the kernel, try downgrading the kernel a version, and/or from these logs try disabling power_save on the snd-hda-intel module eith e.g. /etc/modprobe.d/disablePower.conf

options snd_hda_intel power_save=0

Last edited by V1del (2022-02-12 14:02:02)

Smit · 2022-02-16 05:26:04

Its hard to know if your solution works or not as there is 50/50 chance of sound working in linux-zen.
For the first time I notice this issue also in linux-lts this morning.

3 reboots on linux-zen and your solution seems to be working.

Also this does look like my sound card issue(which was working fine for last 3 years and until now) as I installed piperwire and sound does not work in it too. ( but I can at least kill pipewire-pulse)

Btw how do you came to conclusion of of disabling power saving ?

V1del · 2022-02-16 10:17:59

There's a lot of pm (aka power management) runtime and resuming issues, which can be a hint towards power saving, it also can generally cause some weird issues (personal anectode, my laptop had a short circuiting issue with power save enabled, where it would just turn off as if you'd jank the power cable with no battery if you plugged something into the headphone jack and the card wasn't yet in active use... I think that got fixed somewhere down the line but haven't tested recently and not that eager to) but more commonly usually some static/popping while beginning/during playback.

In any case this is definitely kernel level so switching to pipewire has predictably no change on this (... and pulse hasn't seen an update in half a year, I know people are often eager to blame it, but it logically and physically can't be the cause of an issue that just now surfaced - it might expose it, in which case it's still a kernel bug anyway).

So this is either a bug introduced in the kernel (quite a few ALSA/HDA/realtek changes in 5.16.8, test 5.16.7 or lower, LTS doesn't really count as "stable" patches are generally backported) or maybe (big, quite unlikely) maybe in linux-firmware. Or the HW being toast. The least invasive test here would still be , test a lower kernel. If it's a software issue it's almost certainly a change introduced in 5.16.8

Last edited by V1del (2022-02-16 10:24:49)

Arch Linux

#1 2022-02-12 05:14:02

Pulseaudio gets stuck and wont die

#2 2022-02-12 14:01:05

Re: Pulseaudio gets stuck and wont die

#3 2022-02-16 05:26:04

Re: Pulseaudio gets stuck and wont die

#4 2022-02-16 10:17:59

Re: Pulseaudio gets stuck and wont die

Board footer