- Package:
- pulseaudio
- Source:
- pulseaudio
- Description:
- PulseAudio sound server
- Submitter:
- MichaÅ MirosÅaw
- Date:
- 2023-03-12 14:27:03 UTC
- Severity:
- important
--- Please enter the report below this line. ---
There is some weird interaction of pulseaudio with emu10k1 ALSA driver.
Sometimes it can't start playback, but just eats 100% CPU and spams
system logs (if allowed) with "Resume failed, couldn't restore original
sample settings."
I managed to catch in a debugging session that at
modules/alsa/alsa-sink.c:1099:
(gdb) p u->sink->sample_spec
$9 = {format = PA_SAMPLE_S16LE, rate = 44100, channels = 2 '\002'}
(gdb) p ss
$11 = {format = PA_SAMPLE_S16LE, rate = 48000, channels = 2 '\002'}
This stopped (resulting in working sound) after I changed
/etc/pulse/daemon.conf's default-sample-rate from 48000 to 44100,
commented alternate-sample-rate 44100 line and killed pulseaudio. The
problem didn't reappear after reverting the changes and killing
pulseaudio again, though.
Debian Release: stretch/sid
900 testing ftp.icm.edu.pl
800 jessie-backports ftp.icm.edu.pl
750 stable www.deb-multimedia.org
750 stable security.debian.org
750 stable repos.fds-team.de
750 stable ftp.icm.edu.pl
700 unstable ftp.icm.edu.pl
600 experimental ftp.icm.edu.pl
500 unstable-debug debug.mirrors.debian.org
500 testing-debug debug.mirrors.debian.org
500 stable deb.opera.com
500 proposed-updates ftp.icm.edu.pl
1 experimental-debug debug.mirrors.debian.org
--- Package information. ---
Depends (Version) | Installed
=======================================================-+-=======================
libasound2 (>= 1.0.24.1) |
libc6 (>= 2.15) |
libcap2 (>= 1:2.10) |
libdbus-1-3 (>= 1.9.14) |
libfftw3-single3 |
libgcc1 (>= 1:3.0) |
libice6 (>= 1:1.0.0) |
libltdl7 (>= 2.4.6) |
liborc-0.4-0 (>= 1:0.4.25) |
libpulse0 (= 8.0-2+b2) |
libsm6 |
libsndfile1 (>= 1.0.20) |
libsoxr0 (>= 0.1.0) |
libspeexdsp1 (>= 1.2~beta3.2-1) |
libstdc++6 (>= 4.1.1) |
libsystemd0 |
libtdb1 (>= 1.2.7+git20101214) |
libudev1 (>= 183) |
libwebrtc-audio-processing-0 |
libx11-6 |
libx11-xcb1 |
libxcb1 |
libxtst6 |
adduser |
lsb-base (>= 3.2-13) |
udev (>= 143) |
libasound2-plugins |
pulseaudio-utils |
Recommends (Version) | Installed
====================================-+-===========
pulseaudio-module-x11 | 8.0-2+b2
rtkit | 0.11-4
Suggests (Version) | Installed
==========================-+-===========
pavumeter |
pavucontrol | 3.0-3+b2
paman |
paprefs |
It locked up again. Commenting out alternate-sample-rate works as a workaround.
Control: tags -1 moreinfo Could you attach a verbose log of the problem appearing? Instructions to do so are here: https://wiki.ubuntu.com/PulseAudio/Log
Hi, Did this ever work? Could you try with a different kernel (in particular, with the stock ones debian provides)? Looks like a driver bug to me, as the driver for some reason can be successfully changed one time, but not after suspend-resume: ( 27.938| 0.000) D: [pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"s16le\"" format.rate = "44100" format.channels = "2" format.channel_map = "\"front-left,front-right\"" ( 27.938| 0.000) I: [pulseaudio] sink-input.c: Trying to change sample rate ( 27.938| 0.000) D: [pulseaudio] sink.c: Suspending sink alsa_output.pci-0000_07_01.0.analog-stereo due to changing the sample rate. ( 27.938| 0.000) I: [pulseaudio] alsa-sink.c: Updating rate for device front:1, new rate is 44100 ( 27.938| 0.000) D: [pulseaudio] source.c: Suspending source alsa_output.pci-0000_07_01.0.analog-stereo.monitor due to changing the sample rate. ( 27.938| 0.000) I: [pulseaudio] source.c: Changed sampling rate successfully ( 27.938| 0.000) I: [pulseaudio] sink.c: Changed sampling rate successfully ( 27.938| 0.000) I: [pulseaudio] sink-input.c: Rate changed to 44100 Hz ( 27.938| 0.000) I: [pulseaudio] module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:MPlayer. ( 27.938| 0.000) I: [pulseaudio] module-stream-restore.c: Restoring mute state for sink input sink-input-by-application-name:MPlayer. ( 27.938| 0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_07_01.0.analog-stereo becomes busy, resuming. ( 27.938| 0.000) D: [pulseaudio] sink.c: Suspend cause of sink alsa_output.pci-0000_07_01.0.analog-stereo is 0x0000, resuming ( 27.938| 0.000) D: [pulseaudio] reserve-wrap.c: Successfully acquired reservation lock on device 'Audio1' ( 27.938| 0.000) I: [alsa-sink-emu10k1] alsa-sink.c: Trying resume... ( 27.939| 0.000) I: [alsa-sink-emu10k1] alsa-util.c: Cannot disable ALSA period wakeups ( 27.939| 0.000) D: [alsa-sink-emu10k1] alsa-util.c: Maximum hw buffer size is 341 ms ( 27.939| 0.000) D: [alsa-sink-emu10k1] alsa-util.c: Set buffer size first (to 17832 samples), period size second (to 17832 samples). ( 27.939| 0.000) I: [alsa-sink-emu10k1] alsa-util.c: Device front:1 doesn't support 44100 Hz, changed to 48000 Hz. Also, please give a try to the pulseaudio version in experimental, to see if that improves the issue. There may still be a pulseaudio bug, in that it should probably not keep getting stuck in the suspend-resume loop...
[...] I'm not sure. I'll try some older kernels if I can get them to work. Both 8.99.1 and the latest 9.0 from sid fail the same way. Logs attached. Best Regards, Michał Mirosław
retitle 828190 [pulseaudio] sometimes locks up tag 828190 - moreinfo stop Dear Maintainer, this report is tagged "moreinfo", but I don't see which info is missing. AFAICS the original submitter provided everything he was asked. Please add the tag again and clarify, if indeed some information is missing. Also I want to refute the theory, that this problem is mostly a bug in the kernel driver: Everything works for me, if I use ALSA directly instead of via pulseaudio and duckduckgo finds variants of this problem reported on the internet related to many different drivers. Here are my observations: On my system audio mostly works fine for trivial things like beeps or playing .wav files. However advanced uses (mostly VoIP software like empathy, pidgin and baresip) cause pulseaudio to run at 100% CPU (one thread) and spam syslog with this message Mar 31 00:19:02 teres pulseaudio[9099]: W: [alsa-source-1c22c00.dai-sun8i sun8i-0] alsa-source.c: Resume failed, couldn't restore original sample settings. about 315 times per second. The really fun part: After executing pulseaudio -k; pulseaudio --log-level=4 --log-target=stderr I can't reproduce the issue. Must be some race involved somewhere. The system is set up with pulse as the default ALSA device. Interaction with pulseaudio typically happens via the ALSA API. From the difficulty in reproducing the behaviour and the content of the message I gather, that the trigger depends on the state of the audio HW/alsa and the properties of the audio data to be played. Eg. Simply playing an audio file from baresip usually works fine from a pristine state, but might fail if earlier activity caused the messages to appear. Using "aplay" to play a .wav file might restore a working state. From reading [1] and [2] I understand, that mismatched sample rates might cause such a problem. But pulseaudio should resample as needed to avoid this. Upstream bug [3] might be related somewhat. I focused my efforts for analyzing this problem with baresip, because it has the most straight forward and easy to understand code. I can reproduce this without any other audio applications running, so it really seems like pulseaudio is stepping on its own toes. The versions in unstable and experimental are both affected. The code in baresip, responsible for handling audio is at: https://github.com/alfredh/baresip/blob/be4448a54117cfd2cda69d4fc88e1c2802e8a5b6/modules/alsa/alsa_play.c#L53 If the ALSA API immediatly returns an error without blocking at all, this code turns into a tight loop. Neatly explaining why the system hangs with 100% CPU. I guess this code should be smarter about handling errors. OTOH I don't see anything illegal happening there and pulseaudio should resample instead of throwing errors, so the main problem must be with pulseaudio.--- begin --- static void *write_thread(void *arg) { struct auplay_st *st = arg; int n; int num_frames; num_frames = st->prm.srate * st->prm.ptime / 1000; while (st->run) { const int samples = num_frames; void *sampv; st->wh(st->sampv, st->sampc, st->arg); sampv = st->sampv; n = snd_pcm_writei(st->write, sampv, samples); if (-EPIPE == n) { snd_pcm_prepare(st->write); n = snd_pcm_writei(st->write, sampv, samples); if (n != samples) { warning("alsa: write error: %s\n", snd_strerror(n)); } } else if (n < 0) { warning("alsa: write error: %s\n", snd_strerror(n)); } else if (n != samples) { warning("alsa: write: wrote %d of %d samples\n", n, samples); } } snd_pcm_drain(st->write); return NULL; } --- end --- I might dig into this further in the coming days, but since I'm very much not familiar with ALSA, pulseaudio and debugging threaded applications, some help would be much appreciated. I'm mostly writing this to tell you, that I can reproduce this issue at will (mostly, considering I couln't get debug level logs) and can run any tests you might need. But figuring out how to make pulseaudio smarter about switching sample rates or how to make the debian package detect, that alternate sample rates might not be a good idea on any given system, is probably above my paygrade. [1] https://pulseaudio-discuss.freedesktop.narkive.com/KCt6OOkP/testing-echo-cancellation-on-an-armhf-omap-phone [2] https://arunraghavan.net/2011/10/alternate-sample-rates/ [3] https://gitlab.freedesktop.org/pulseaudio/pulseaudio/-/issues/374
Hi, I have been wrong in at least one part of my previous update to this bug. Even if I stop all threads in the sound application (in my case baresip) in the debugger, pulseaudio still run's at 100% CPU spamming syslog. Only killing baresip (probably the closing of file descriptors) makes pulseaudio recover. I got confused, because somehow this situation causes an other thread of baresip consume lot's of CPU, which made me believe that there is a rather tight loop between baresip and pulseaudio. Actually the calls to the sound API never return while pulseaudio is busy, thus the application never get's an error and can't actually close its ALSA handles. So at this point I'm convinced the entire problem is within pulseaudio. Since baresip is not a pulseaudio but an ALSA application, works fine without pulseaudio installed and only uses pulseaudio because pulseaudio makes itself the default ALSA device on installation, I think it is fair to say that pulseaudio is breaking unrelated software here. I'm tempted to raise the severity of this bug to release critical, but I guess this should be at the discretion of the maintainers. This is clearly a (probably rather old) upstream bug. It seems to mostly manifest itself with SoC devices, which might explain why it is more often seen recently and with debian: Debian arm ports are quite popular with users of SoC based laptops. From the debian packaging PoV I can see two possible workarounds: * Disable sample rate switching by setting defaut-sample-rate and alternate-sample-rate to the same value by default for the ARM based ports and prominently document the problem for everybody else. * Don't enable pulseaudio at all on ARM based ports without some kind of manual intervention by the local admin. HTH, Harald
Looking at perf and strace output, the case looks similar to what was described in an upstream commit [1] and its backing bug report [2]. (Haven't tried the workarounds nor testing or newer version, yet.) [1] https://gitlab.freedesktop.org/pulseaudio/pulseaudio/-/commit/37358e42c49abe3d83b344452749461b70fdc80f [2] https://bugzilla.kernel.org/show_bug.cgi?id=199365#c6
[...] Disabling `load-module module-suspend-on-idle` in `default.pa` seems to also work around the problem.