Description of problem: Received warning that my disk was full (unpartitioned disk inside a KVM virtual machine). Noticed that /var was 2.2G (out of 8G disk). Looked further and saw that /var/log/messages was 2.2G. Tailed it and saw these messages being spammed at high speed over and over: Dec 3 15:16:02 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 15:16:02 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 15:16:02 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 15:16:02 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 15:16:02 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files I had to kill the pulseaudio process and delete other files just to be able to try to compress messages. Version-Release number of selected component (if applicable): pulseaudio-0.9.21-1.fc12.x86_64 How reproducible: Have not yet tried. Additional info: When the messages file finishes compressing, I'll reboot the VM and see if the problem occurs. This VM was just created yesterday.
Finally copied the log to my host wher I have more disk. Here's where the trouble started, just earlier today. These messages are sequential, I haven't deleted any lines from the log, just changed the name of my machine hostname to "foo": Dec 3 09:21:20 foo pulseaudio[1465]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pc m_avail() returned 0 or another value < min_avail. Dec 3 09:31:03 foo avahi-daemon[817]: Received response from host 172.16.30.3 with invalid source port 58346 on in terface 'eth0.0' Dec 3 14:05:42 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:05:42 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:08:04 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:11:08 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:11:08 foo pulseaudio[1465]: sink-input.c: Failed to create sink input: sink is suspended. Dec 3 14:13:10 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:13:29 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:13:36 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:13:57 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:14:27 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:15:36 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:16:32 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:17:24 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:17:36 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:17:47 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:17:58 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:18:04 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:18:12 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:18:20 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:19:41 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:20:01 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:20:26 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:23:33 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:23:46 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:24:12 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:24:40 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:24:40 foo pulseaudio[1465]: sink-input.c: Failed to create sink input: sink is suspended. Dec 3 14:28:09 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:28:15 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:29:14 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:29:17 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:29:17 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:30:29 foo pulseaudio[1465]: alsa-sink.c: Error opening PCM device front:0: Too many open files Dec 3 14:30:29 foo pulseaudio[1465]: shm.c: shm_open() failed: Too many open files Dec 3 14:30:29 foo pulseaudio[1465]: shm.c: shm_open() failed: Too many open files Dec 3 14:30:29 foo pulseaudio[1465]: shm.c: shm_open() failed: Too many open files Dec 3 14:32:33 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 14:32:33 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files Dec 3 14:32:33 foo pulseaudio[1465]: socket-server.c: accept(): Too many open files After this it's madness as I posted earlier. Hundreds of screenfuls of the same line with the same exact timestamp.
Happened again today. First a number of these messages in rapid succession (all with same exact timestamp): Dec 9 09:42:06 foo pulseaudio[1517]: shm.c: shm_open() failed: Too many open files Followed by a LOT of these until /var/log/messages fills up the root disk: Dec 9 09:42:07 foo pulseaudio[1517]: socket-server.c: accept(): Too many open files Have to kill the pulseaudio pid 1517 and then just truncate /var/log/messages.
In case it wasn't clear before, this is happening in my Fedora 12 KVM virtual machine. The host is also Fedora 12 with all available stable upgrades. No pulseaudio problems on the host, just in the VM. The VM also has all available Fedora 12 stable upgrades. I'm more than willing to post whatever information is required, if you are available to help. It seems like a serious bug to me if pulseaudio is allowed to fill up the partition hosting /var/log/messages. In my case, this is the root partition, and it filled 2.2G in around 45 minutes.
Found a somewhat similar bug for Ubuntu: https://bugs.launchpad.net/ubuntu/+source/pulseaudio/+bug/451893 I see similar cases of a number of timer links. I have no real idea what it means. [root@foo ~]# ls -l /proc/$(pgrep pulseaudio)/fd|grep timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 22 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 23 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 29 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 30 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 35 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 36 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 37 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 38 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 39 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 40 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 41 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 42 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 11:03 43 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 11:03 44 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 11:03 45 -> /dev/snd/timer lr-x------. 1 seiler seiler 64 2009-12-09 10:56 9 -> /dev/snd/timer
FYI: # pulseaudio --version pulseaudio 0.9.21 # rpm -qa | grep pulseaudio pulseaudio-libs-glib2-0.9.21-1.fc12.x86_64 pulseaudio-module-gconf-0.9.21-1.fc12.x86_64 pulseaudio-utils-0.9.21-1.fc12.x86_64 pulseaudio-0.9.21-1.fc12.x86_64 pulseaudio-libs-0.9.21-1.fc12.x86_64 pulseaudio-module-bluetooth-0.9.21-1.fc12.x86_64 alsa-plugins-pulseaudio-1.0.21-2.fc12.x86_64 pulseaudio-gdm-hooks-0.9.21-1.fc12.x86_64 pulseaudio-module-x11-0.9.21-1.fc12.x86_64
I'm seeing this behaviour as well on a fully updated F12 host (no KVM). As far as I can tell, it is usually triggered by flash (flash-plugin-10.0.42.34-release.i386). Excerpts from /var/log/messages: Dec 6 13:50:29 batcave pulseaudio[1842]: ratelimit.c: 78 events suppressed Dec 6 13:51:01 batcave pulseaudio[1842]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Dec 6 13:51:01 batcave pulseaudio[1842]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_emu10k1'. Please report this issue to the ALSA devel opers. Dec 6 13:51:01 batcave pulseaudio[1842]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail. Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: No such device [repeats until..] Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: No such device Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-util.c: Unable to set sw params: Too many open files Dec 6 14:04:51 batcave pulseaudio[1842]: alsa-sink.c: Failed to set software parameters: Too many open files This continues till I notice and kill pulseaudio or till I run out of space on /. This is a pretty serious problem and I hope it can be resolved quickly. Please let me know if I can help with more information.
Looks as if something is leaking fds in either PA or in libasound.
Oh, and one thing really sucks: rsyslog does not automatically rate limit log output from all processes. That's a real disaster if you ask me.
OK, seems that alsa-lib is at fault here. Reassigning. http://git.alsa-project.org/?p=alsa-lib.git;a=commit;h=a256766c10c52cb6667de8a65f5cbb332fad4cc7
This just hit me again. I see that ubuntu has pushed the patch into their repos. Any ETA on Fedora 12 patch?
The patch is in alsa-lib-1.0.22-1 package.
My yum.log shows that I installed that package on Jan 7. I thought I had this occur again on the 8th, but can't be sure now. Anyway I'll be sure to note any re-occurrence.