Created attachment 126276 [details] log file while trying to play audio with paplay I'm unable to play audio inside a VirtualBox virtual machine. Simple clients hang when trying to output audio, and YouTube videos played inside Chromium are silent. $ time paplay /usr/share/sounds/gnome/default/alerts/sonar.ogg Failed to drain stream: Timeout real 0m30.046s user 0m0.012s sys 0m0.000s $ cat /proc/asound/cards 0 [I82801AAICH ]: ICH - Intel 82801AA-ICH Intel 82801AA-ICH with STAC9700,83,84 at irq 21 Playing audio directly through ALSA works fine. If I do so with pasuspender, then when pulseaudio resumes, pulseaudio clients are able to play sounds for a few moments; however shortly afterwards they will start hanging again, until the server is once again suspended.
Created attachment 126277 [details] log file when suspending pulseaudio and then trying to play audio This was generated by running `pasuspender -- speaker-test -c 2 -t wav -D plughw:CARD=I82801AAICH,DEV=0` (which worked fine); then running `paplay /usr/share/sounds/gnome/default/alerts/sonar.ogg` which worked, then waiting a few seconds, then running paplay a second time, which failed after timing out. Line 1738 ("module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_05.0.analog-stereo idle for too long, suspending ...") was logged after the successful paplay command, but before the paplay command that hangs.
Could you post the log when you do this following (ideally also include times in log (log-time = true in daemon.conf or --log-time). 1. Start PA 2. Play a sound 3. Wait >5 seconds with no sounds (suspend will kick in) 4. Play a sound again Also, for step 4., run paplay with PULSE_LOG=4 in the environment and provide that output too.
Created attachment 126294 [details] pulseaudio.log While trying to do this I actaully had problems playing the sound successfully, even though I was running paplay immediately after launching pulseaudio! This log file is for such a run, where I only run paplay a single time, and then wait for it to fail with the timeout error. paplay output: Parsing configuration file '/etc/pulse/client.conf' /etc/pulse/client.conf.d does not exist, ignoring. 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 Trying to connect to /run/user/1000/pulse/native... SHM possible: yes Protocol version: remote 31, local 31 Negotiated SHM: yes Memfd possible: yes Negotiated SHM type: shared posix-shm Failed to drain stream: Timeout
Created attachment 126295 [details] pulseaudio2.log Continuing from the last log file, I then tried launching pulseaudio, and then running `pasuspender -- speaker-test -c 2 -t wav -D plughw:CARD=I82801AAICH,DEV=0`. After killing speaker-test, paplay worked fine! So here's a log of that.
Created attachment 126299 [details] pulseaudio3.log This time paplay worked, though the sound was played at half speed with gaps in it so that a portion of the sound would play, then there would be silence, then it would play the next portion, etc. I've not seen that behaviour before... then I waited for the suspend message to be logged, and ran paplay again, and as expected it timed out. BTW, the output from paplay with PULSE_LOG=4 didn't change each time, even when the audio sounded strange; the only difference is whether it logs the 'Failed to drain stream: Timeout' message at the end.
Could you also do the same test but also set PULSE_LOG_TIME=1 for paplay -- that'll give a better idea of how long things are taking. I don't see any errors on the server side logs.
(also, is the audio audible and the only problem the timeout message?)
$ PULSE_LOG_TIME=1 PULSE_LOG=4 paplay /usr/share/sounds/gnome/default/alerts/sonar.ogg ( 0.000| 0.000) Parsing configuration file '/home/sam/.config/pulse/client.conf' ( 0.000| 0.000) /home/sam/.config/pulse/client.conf.d does not exist, ignoring. ( 0.002| 0.002) 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 ( 0.002| 0.000) Trying to connect to /run/user/1000/pulse/native... ( 0.003| 0.000) SHM possible: yes ( 0.003| 0.000) Protocol version: remote 31, local 31 ( 0.003| 0.000) Negotiated SHM: yes ( 0.003| 0.000) Memfd possible: yes ( 0.003| 0.000) Negotiated SHM type: shared posix-shm ( 30.026| 30.022) Failed to drain stream: Timeout When paplay is hanging there is no audio from any program. If I run something (aplay, speaker-test) via pasuspender then that program can play audio fine. When pasuspender exits, programs that are trying to play audio all unhang and play normally. But once the device suspends again, we're back to square one, where any thread trying to play audio hangs again.
That's a bit odd. The client side log shows that things aren't working at all. But I don't see the problem on the server side. Just as a sanity check, the previous logs you posted are from when the playback didn't work?
Well, it's a mix as described. But I don't see any significant differences in the output of the server when trying to play audio in the working and not-working state. The only thing that gets it to work is to run papsuspender, then try playing something before the server logs "I: [alsa-sink-Intel ICH] alsa-sink.c: Device suspended..."; after that happens, I have to run pasuspender again.
Created attachment 126303 [details] pulseaudio4.log Just to be really clear: in this log I started the server, then ran paplay, which timed out after 30 seconds without playing any sound.
I'm a bit stumped at this point. I see nothing going wrong as such in the server logs, but the client seems to die arbitrarily. Is there any sort of firewalling/jailing happening in your setup? I'm officially throwing out random ideas at this point. :/
A stack trace might be useful. Are you familiar with using gdb? There are some instructions on https://wiki.freedesktop.org/www/Software/PulseAudio/Documentation/User/Community/ Basically, you need to install debug symbols for pulseaudio, start pulseaudio with gdb --args pulseaudio --log-time -vv then start the program with command "run". Then, trigger the bug, and hit ctrl-c when it's stuck. Then run "thread apply all bt". It should show what is blocking the server.
I've now observed aplay itself hanging while trying to play audio, even when pulseaudio isn't running, though I can't reproduce that anywhere near as reliably as I can than with PA trying to play audio. So I'm starting to suspect the (virtual) hardware. If that's the case then maybe there's nothing that can really be done in PA itself--though perhaps detecting that it's stuck in this state and logging something would be possible... Anyway, here's a backtrace: Thread 2 (Thread 0x7ffad0e65700 (LWP 16522)): #0 0x00007ffadab73161 in __GI_ppoll (fds=0x1130090, nfds=5, timeout=<optimized out>, sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:50 #1 0x00007ffadc2ce3f8 in ppoll (__ss=0x0, __timeout=<optimized out>, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/poll2.h:77 #2 pa_rtpoll_run (p=0x1033c40) at pulsecore/rtpoll.c:314 #3 0x00007ffad0e8ffed in thread_func (userdata=0x11302c0) at modules/alsa/alsa-sink.c:1799 #4 0x00007ffadc069dc8 in ?? () from /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-9.0.so #5 0x00007ffadb54e444 in start_thread (arg=0x7ffad0e65700) at pthread_create.c:333 #6 0x00007ffadab7c20d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109 Thread 1 (Thread 0x7ffadc6a2940 (LWP 16521)): #0 0x00007ffadab73161 in __GI_ppoll (fds=0x10b84a0, nfds=36, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:50 #1 0x00007ffadbde833d in pa_mainloop_poll () from /usr/lib/x86_64-linux-gnu/libpulse.so.0 #2 0x00007ffadbde892e in pa_mainloop_iterate () from /usr/lib/x86_64-linux-gnu/libpulse.so.0 #3 0x00007ffadbde89e0 in pa_mainloop_run () from /usr/lib/x86_64-linux-gnu/libpulse.so.0 #4 0x0000000000406d32 in main (argc=<optimized out>, argv=<optimized out>) at daemon/main.c:1141
The backtrace doesn't show anything that would indicate a hang. Did you hit ctrl-c quickly enough after detecting a hang? Both threads are idle, waiting in the ppoll() call that something would happen.
That was actually obtained by connecting gdb to pulseaudio after it had stopped playing audio. Perhaps 'hang' is not the right technical term to use; it just seemed the most straightforward way to describe the behaviour of client programs.
Yes, a server hang would have been the most obvious explanation. I expected to see some alsa call to be blocking or something like that. pulseaudio4.log shows also an error from a timed out dbus call. It looks like the dbus daemon tried to start bluetoothd, but that took a long time. I don't think bluetooth is to blame, since I don't think we try to talk to bluetoothd after the initial failure, and you experience the problem also at other times than just after starting pulseaudio. But whatever is causing the problem seems to affect other parts of the system too.
A bug with similar symptoms was reported here: https://bugs.freedesktop.org/show_bug.cgi?id=97874
FYI the VirtualBox side of this appears to have been fixed and I'm no longer able to reproduce it. I understand if you don't want to put any effort into dealing with the unreasonable behaviour of (emulated) hardware, so feel free to resolve this.
Thanks for the update! I'm closing this now.
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.