[Pkg-utopia-maintainers] Bug#1076803: Random corrupt audio output when starting new stream

Tue Jul 23 13:50:09 BST 2024

Package: pipewire
Version: 1.2.1-1

Seemingly randomly when a new audio stream is started, I get a completely garbled audio output on this Dell Precision 5680 (card: Raptor Lake-P/U/H cAVS). The issue is reproducible and occurs approximately after 1-2h of normal usage. It survived a Debian reinstall and a fresh home directory, so it shouldn't be caused by any non-standard configuration. It did not occur on openSUSE Tumbleweed or NixOS which I had running for a few months without this problem showing up.

I can reliably reproduce the issue within a few seconds by following these steps:

1. Start a audio / video stream (to recognize when the corruption occurs)
2. Open pavucontrol
3. Move the output device volume slider up and down until pipewire hangs (takes ~5 to 10s on my system)

The volume notification sound of pavucontrol causes the pipewire daemon to start hanging and the audio output to be completely garbled after a few seconds.

When the issue occurs the thread irq/206-AudioDSP and pipewire both max one CPU core each. Pipewire does not react to SIGTERM, but a SIGKILL resolves the problem for the next few hour or two.

journalctl output when this occurs (messages repeat for all possible sinks / sources):

pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Headphones__sink-75) graph xrun (0 suppressed)
pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Headphones__sink-75) graph xrun (0 suppressed)
pw.node: (alsa_input.usb-046d_Logitech_BRIO_8C4E596F-03.analog-stereo-69) xrun state:0x7f2441b1d008 pending:6/6 s:53992791238199 a:53992785859966 f:53992785865055 waiting:18446744073704173383 process:5089 status:triggered (1 suppressed)
pw.node: (alsa_input.usb-GN_Audio_A_S_Jabra_Engage_75_0372BEEEB00F-00.mono-fallback-70) xrun state:0x7f2440894008 pending:2/2 s:53992805618782 a:53992786852281 f:53992786853262 waiting:18446744073690785115 process:981 status:triggered (0 suppressed)
pw.node: (alsa_output.usb-GN_Audio_A_S_Jabra_Engage_75_0372BEEEB00F-00.analog-stereo-71) xrun state:0x7f2440895008 pending:4/4 s:53992805645058 a:53992786908463 f:53992786914259 waiting:18446744073690815021 process:5796 status:triggered (0 suppressed)
pw.node: (alsa_input.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Headset__source-77) xrun state:0x7f244088e008 pending:2/2 s:53992828713916 a:53992789488342 f:53992789489380 waiting:18446744073670326042 process:1038 status:triggered (0 suppressed)
pw.node: (alsa_input.pci-0000_00_1f.3-platform-sof_sdw.HiFi__Mic__source-78) xrun state:0x7f244088d008 pending:2/2 s:53992828721419 a:53992789654514 f:53992789655553 waiting:18446744073670484711 process:1039 status:triggered (0 suppressed)
pw.node: (alsa_input.usb-046d_Logitech_BRIO_8C4E596F-03.analog-stereo-69) xrun state:0x7f2441b1d008 pending:6/6 s:53994782646740 a:53994782577552 f:53994782580175 waiting:18446744073709482428 process:2623 status:triggered (26 suppressed)
pw.node: (alsa_input.usb-GN_Audio_A_S_Jabra_Engage_75_0372BEEEB00F-00.mono-fallback-70) xrun state:0x7f2440894008 pending:2/2 s:53994832729317 a:53994819613817 f:53994819615431 waiting:18446744073696436116 process:1614 status:triggered (25 suppressed)
pw.node: (alsa_output.usb-GN_Audio_A_S_Jabra_Engage_75_0372BEEEB00F-00.analog-stereo-71) xrun state:0x7f2440895008 pending:4/4 s:53994832748832 a:53994819615502 f:53994819661191 waiting:18446744073696418286 process:45689 status:triggered (25 suppressed)
pw.node: (alsa_output.pci-0000_00_1f.3-platform-sof_sdw.HiFi__HDMI3__sink-72) xrun state:0x7f2440893008 pending:2/2 s:53996793583999 a:53996779519697 f:53996779532367 waiting:18446744073695487314 process:12670 status:triggered (76 suppressed)

Backtrace for pipewire when this occurs:

(gdb) thread apply all bt

Thread 3 (Thread 0x7f5385a006c0 (LWP 174283) "data-loop.0"):
#0  0x00007f538710f536 in epoll_wait (epfd=8, events=events at entry=0x7f53859ffa20, maxevents=32, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x00007f5386ffb638 in impl_pollfd_wait (object=<optimized out>, pfd=<optimized out>, ev=0x7f53859ffbf0, n_ev=<optimized out>, timeout=<optimized out>) at ../spa/plugins/support/system.c:138
#2  0x00007f5386fec66d in loop_iterate (object=object at entry=0x55a36566a668, timeout=timeout at entry=-1) at ../spa/plugins/support/loop.c:570
#3  0x00007f53872468b0 in do_loop (user_data=0x55a36566a4d0) at ../src/pipewire/data-loop.c:67
#4  0x00007f53870946b2 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
#5  0x00007f538710ef70 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 2 (Thread 0x7f5386a006c0 (LWP 174282) "module-rt"):
#0  0x00007f538710f536 in epoll_wait (epfd=12, events=events at entry=0x7f53869ffab0, maxevents=32, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x00007f5386ffb638 in impl_pollfd_wait (object=<optimized out>, pfd=<optimized out>, ev=0x7f53869ffc80, n_ev=<optimized out>, timeout=<optimized out>) at ../spa/plugins/support/system.c:138
#2  0x00007f5386fec66d in loop_iterate (object=0x55a365672348, timeout=-1) at ../spa/plugins/support/loop.c:570
#3  0x00007f53872adaa5 in do_loop (user_data=0x55a365672130) at ../src/pipewire/thread-loop.c:294
#4  0x00007f53870946b2 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
#5  0x00007f538710ef70 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 1 (Thread 0x7f5387005740 (LWP 174278) "pipewire-pulse"):
#0  0x00007f538710f536 in epoll_wait (epfd=4, events=events at entry=0x7ffc39aa0bf0, maxevents=32, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x00007f5386ffb638 in impl_pollfd_wait (object=<optimized out>, pfd=<optimized out>, ev=0x7ffc39aa0dc0, n_ev=<optimized out>, timeout=<optimized out>) at ../spa/plugins/support/system.c:138
#2  0x00007f5386fec66d in loop_iterate (object=0x55a365663d08, timeout=-1) at ../spa/plugins/support/loop.c:570
#3  0x00007f538726c508 in pw_main_loop_run (loop=loop at entry=0x55a365663ba0) at ../src/pipewire/main-loop.c:130
#4  0x000055a352b8a693 in main (argc=<optimized out>, argv=<optimized out>) at ../src/daemon/pipewire.c:130

System information:

Kernel: Linux hostname 6.9.9-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.9.9-1 (2024-07-13) x86_64 GNU/Linux
libc: 2.39-4
libpulse-mainloop-glib0/testing,now 16.1+dfsg1-5.1 amd64 [installed,automatic]
libpulse0/testing,now 16.1+dfsg1-5.1 amd64 [installed,automatic]
libpulsedsp/testing,now 16.1+dfsg1-5.1 amd64 [installed,automatic]
libasound2t64/testing,now 1.2.12-1 amd64 [installed,automatic]
pipewire-alsa/testing,now 1.2.1-1 amd64 [installed,automatic]

Hardware information:
00:1f.3 Multimedia audio controller: Intel Corporation Raptor Lake-P/U/H cAVS (rev 01)
	Subsystem: Dell Device 0c11
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 64
	Interrupt: pin A routed to IRQ 206
	IOMMU group: 18
	Region 0: Memory at 603e1a0000 (64-bit, non-prefetchable) [size=16K]
	Region 4: Memory at 603e000000 (64-bit, non-prefetchable) [size=1M]
	Capabilities: <access denied>
	Kernel driver in use: sof-audio-pci-intel-tgl
	Kernel modules: snd_hda_intel, snd_soc_avs, snd_sof_pci_intel_tgl