Description of problem: See this every now and then in /var/log/messages: Sep 10 17:23:31 tlondon pulseaudio[3177]: shm.c: shm_open() failed: No such file or directory Sep 10 17:23:31 tlondon pulseaudio[3177]: pstream.c: Failed to import memory block. Not sure it's a problem..... Version-Release number of selected component (if applicable): pulseaudio-0.9.12-4.fc10.i386 How reproducible: Intermittant Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
Hmm, normally the SHM files of all clients should be accessible in /dev/shm. The output you are experiencing suggests that either that path got missing on your machine or the shm segs in it. Is SELinux enabled? Could you please set log-level=debug in /etc/pulse/default.pa and the logout and login again, and post a more complete excerpt from syslog when this happens?
SELinux is enabled, but these come out after pulse/rhythmbox has been running for hours. Sorry, but what exactly is the format of the line to be added to default.pa (couldn't find anything close in the man pages or in http://pulseaudio.org/wiki/CLI? Is it "set log-level=debug" or just "log-level=debug"? A bit more on the scenario: I start rhythmbox pretty much immediately after I login to gnome, and it just plays and plays through a collection of mp3s that I have stored on a mounted ntfs-3g file system. I occasionally stop/restart rhythmbox when someone comes into my office.
OK, I set 'log-level=debug' in /etc/pulse/daemon.conf and rebooted. That right?
OK, got one. Took almost 2 days.... As above, the setup is system up and running since about 9AM (now 3PM), with rhythmbox pretty much continuously running. I did not notice any interruptions of rhythmbox. I extracted from /var/log/messages the messages from about a 2 minute interval. Let me know if you want the complete day's log (more than 500KB). Sep 12 14:36:04 tlondon pulseaudio[4086]: client.c: Created 71 "Native client (UNIX socket client)" Sep 12 14:36:04 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 12 14:36:05 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 12 14:36:05 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 12 14:36:05 tlondon pulseaudio[4086]: resampler.c: Using resampler 'speex-float-3' Sep 12 14:36:05 tlondon pulseaudio[4086]: resampler.c: Using float32le as working format. Sep 12 14:36:05 tlondon pulseaudio[4086]: resampler.c: Choosing speex quality setting 3. Sep 12 14:36:05 tlondon pulseaudio[4086]: sink-input.c: Created input 55 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 12 14:36:05 tlondon pulseaudio[4086]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 12 14:36:05 tlondon pulseaudio[4086]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 12 14:36:05 tlondon pulseaudio[4086]: sink-input.c: Freeing input 55 "Playback Stream" Sep 12 14:36:05 tlondon pulseaudio[4086]: client.c: Freed 71 "Pidgin" Sep 12 14:36:05 tlondon pulseaudio[4086]: protocol-native.c: Connection died. Sep 12 14:36:14 tlondon pulseaudio[4086]: client.c: Created 72 "Native client (UNIX socket client)" Sep 12 14:36:14 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 12 14:36:14 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 12 14:36:14 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 12 14:36:14 tlondon pulseaudio[4086]: resampler.c: Using resampler 'speex-float-3' Sep 12 14:36:14 tlondon pulseaudio[4086]: resampler.c: Using float32le as working format. Sep 12 14:36:14 tlondon pulseaudio[4086]: resampler.c: Choosing speex quality setting 3. Sep 12 14:36:14 tlondon pulseaudio[4086]: sink-input.c: Created input 56 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 12 14:36:14 tlondon pulseaudio[4086]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 12 14:36:14 tlondon pulseaudio[4086]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 12 14:36:15 tlondon pulseaudio[4086]: sink-input.c: Freeing input 56 "Playback Stream" Sep 12 14:36:15 tlondon pulseaudio[4086]: client.c: Freed 72 "Pidgin" Sep 12 14:36:15 tlondon pulseaudio[4086]: protocol-native.c: Connection died. Sep 12 14:36:24 tlondon pulseaudio[4086]: client.c: Created 73 "Native client (UNIX socket client)" Sep 12 14:36:24 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 12 14:36:24 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 12 14:36:24 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 12 14:36:24 tlondon pulseaudio[4086]: resampler.c: Using resampler 'speex-float-3' Sep 12 14:36:24 tlondon pulseaudio[4086]: resampler.c: Using float32le as working format. Sep 12 14:36:24 tlondon pulseaudio[4086]: resampler.c: Choosing speex quality setting 3. Sep 12 14:36:24 tlondon pulseaudio[4086]: sink-input.c: Created input 57 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 12 14:36:24 tlondon pulseaudio[4086]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 12 14:36:24 tlondon pulseaudio[4086]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 12 14:36:24 tlondon pulseaudio[4086]: sink-input.c: Freeing input 57 "Playback Stream" Sep 12 14:36:24 tlondon pulseaudio[4086]: client.c: Freed 73 "Pidgin" Sep 12 14:36:24 tlondon pulseaudio[4086]: protocol-native.c: Connection died. Sep 12 14:36:32 tlondon pulseaudio[4086]: client.c: Created 74 "Native client (UNIX socket client)" Sep 12 14:36:32 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 12 14:36:32 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 12 14:36:32 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 12 14:36:32 tlondon pulseaudio[4086]: resampler.c: Using resampler 'speex-float-3' Sep 12 14:36:32 tlondon pulseaudio[4086]: resampler.c: Using float32le as working format. Sep 12 14:36:32 tlondon pulseaudio[4086]: resampler.c: Choosing speex quality setting 3. Sep 12 14:36:32 tlondon pulseaudio[4086]: sink-input.c: Created input 58 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 12 14:36:32 tlondon pulseaudio[4086]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 12 14:36:32 tlondon pulseaudio[4086]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 12 14:36:32 tlondon pulseaudio[4086]: sink-input.c: Freeing input 58 "Playback Stream" Sep 12 14:36:32 tlondon pulseaudio[4086]: client.c: Freed 74 "Pidgin" Sep 12 14:36:32 tlondon pulseaudio[4086]: protocol-native.c: Connection died. Sep 12 14:37:46 tlondon pulseaudio[4086]: client.c: Created 75 "Native client (UNIX socket client)" Sep 12 14:37:46 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 12 14:37:46 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 12 14:37:46 tlondon pulseaudio[4086]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 12 14:37:46 tlondon pulseaudio[4086]: resampler.c: Using resampler 'speex-float-3' Sep 12 14:37:46 tlondon pulseaudio[4086]: resampler.c: Using float32le as working format. Sep 12 14:37:46 tlondon pulseaudio[4086]: resampler.c: Choosing speex quality setting 3. Sep 12 14:37:46 tlondon pulseaudio[4086]: sink-input.c: Created input 59 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 12 14:37:46 tlondon pulseaudio[4086]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 12 14:37:46 tlondon pulseaudio[4086]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 12 14:37:47 tlondon pulseaudio[4086]: shm.c: shm_open() failed: No such file or directory Sep 12 14:37:47 tlondon pulseaudio[4086]: pstream.c: Failed to import memory block. Sep 12 14:37:47 tlondon pulseaudio[4086]: sink-input.c: Freeing input 59 "Playback Stream" Sep 12 14:37:47 tlondon pulseaudio[4086]: client.c: Freed 75 "Pidgin" Sep 12 14:37:47 tlondon pulseaudio[4086]: protocol-native.c: Connection died. Sep 12 14:38:12 tlondon pulseaudio[4086]: client.c: Created 76 "Native client (UNIX socket client)" Sep 12 14:38:12 tlondon pulseaudio[4086]: protocol-native.c: Got credentials: uid=500 gid=500 success=1
Here is another one below. I'm checking my old logs, but at least these two occur with pidgin-generated sounds. In general, I have rhythmbox playing (sometimes muted for, say, 5-30 minutes at a time). [Checking my old logs doesn't help, as I didn't have debugging enabled until the report above....] Sep 13 12:57:12 tlondon pulseaudio[3118]: client.c: Created 64 "Native client (UNIX socket client)" Sep 13 12:57:12 tlondon pulseaudio[3118]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 13 12:57:12 tlondon pulseaudio[3118]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 13 12:57:12 tlondon pulseaudio[3118]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 13 12:57:12 tlondon pulseaudio[3118]: resampler.c: Using resampler 'speex-float-3' Sep 13 12:57:12 tlondon pulseaudio[3118]: resampler.c: Using float32le as working format. Sep 13 12:57:12 tlondon pulseaudio[3118]: resampler.c: Choosing speex quality setting 3. Sep 13 12:57:12 tlondon pulseaudio[3118]: sink-input.c: Created input 49 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 13 12:57:12 tlondon pulseaudio[3118]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 13 12:57:12 tlondon pulseaudio[3118]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 13 12:57:14 tlondon pulseaudio[3118]: shm.c: shm_open() failed: No such file or directory Sep 13 12:57:14 tlondon pulseaudio[3118]: pstream.c: Failed to import memory block. Sep 13 12:57:14 tlondon pulseaudio[3118]: sink-input.c: Freeing input 49 "Playback Stream" Sep 13 12:57:14 tlondon pulseaudio[3118]: client.c: Freed 64 "Pidgin"
Not sure its relevant, but here are details of /dev/shm on my system. System has been running for about 3.75 hours, with rhythmbox active most of the time, and pidgin "sounding" intermittantly. [tbl@tlondon shm]$ ls -lZ /dev/shm -r-------- tbl tbl unconfined_u:object_r:unconfined_tmpfs_t:s0 pulse-shm-1454783934 -r-------- tbl tbl unconfined_u:object_r:tmpfs_t:s0 pulse-shm-1693118357 -r-------- tbl tbl unconfined_u:object_r:unconfined_tmpfs_t:s0 pulse-shm-2817906901 -r-------- tbl tbl unconfined_u:object_r:unconfined_tmpfs_t:s0 pulse-shm-323609340 [tbl@tlondon shm]$ ls -l /dev/shm total 848 -r-------- 1 tbl tbl 67108888 2008-09-14 09:10 pulse-shm-1454783934 -r-------- 1 tbl tbl 67108888 2008-09-14 12:49 pulse-shm-1693118357 -r-------- 1 tbl tbl 67108888 2008-09-14 09:10 pulse-shm-2817906901 -r-------- 1 tbl tbl 67108888 2008-09-14 11:55 pulse-shm-323609340 [tbl@tlondon shm]$ Current date: [tbl@tlondon shm]$ date Sun Sep 14 12:54:53 PDT 2008 [tbl@tlondon shm]$ [tbl@tlondon shm]$ uptime 12:55:26 up 3:46, 3 users, load average: 0.34, 0.47, 0.49 [tbl@tlondon shm]$ last | head tbl pts/1 :0.0 Sun Sep 14 09:11 still logged in tbl pts/0 :0.0 Sun Sep 14 09:11 still logged in tbl :0 Sun Sep 14 09:10 still logged in tbl tty7 :0 Sun Sep 14 09:10 still logged in reboot system boot 2.6.27-0.325.rc6 Sun Sep 14 09:09 (03:45)
Got another one of these just now (while rhythmbox was active playing an mp3). Not sure what other information would be helpful/useful. Sep 18 07:30:56 tlondon pulseaudio[3131]: client.c: Created 66 "Native client (UNIX socket client)" Sep 18 07:30:56 tlondon pulseaudio[3131]: protocol-native.c: Got credentials: uid=500 gid=500 success=1 Sep 18 07:30:56 tlondon pulseaudio[3131]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Pidgin. Sep 18 07:30:56 tlondon pulseaudio[3131]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 18 07:30:56 tlondon pulseaudio[3131]: resampler.c: Using resampler 'speex-float-3' Sep 18 07:30:56 tlondon pulseaudio[3131]: resampler.c: Using float32le as working format. Sep 18 07:30:56 tlondon pulseaudio[3131]: resampler.c: Choosing speex quality setting 3. Sep 18 07:30:56 tlondon pulseaudio[3131]: sink-input.c: Created input 47 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 18 07:30:56 tlondon pulseaudio[3131]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 18 07:30:56 tlondon pulseaudio[3131]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 18 07:30:59 tlondon pulseaudio[3131]: shm.c: shm_open() failed: No such file or directory Sep 18 07:30:59 tlondon pulseaudio[3131]: pstream.c: Failed to import memory block. Sep 18 07:30:59 tlondon pulseaudio[3131]: sink-input.c: Freeing input 47 "Playback Stream" Sep 18 07:30:59 tlondon pulseaudio[3131]: client.c: Freed 66 "Pidgin" Sep 18 07:30:59 tlondon pulseaudio[3131]: protocol-native.c: Connection died.
Can you reproduce this if you turn of SELinux?
(I am asking because we have some code in PA that checks /dev/shm from time to time and removes shm segs that belong to apparently dead clients. It might happen that this check doesn't work properly due to SELinux and we remove shm segs of clients that are still around.)
OK. I'll test (although it may take me a few days to report, as this appears to happen ever few days or so). I'll also try to correlate the /var/log/audit/audit.log to see if any of the previous events occurred with SELinux in permissive mode.
Cross checking /var/log/audit/audit.log (for setenforce times) with /var/log/messages (for above messages) appears to indicate that all occurred when running with SELinux enabled, but then again, I run enabled almost all the time....... I'll boot permissive for a while.......
One more thing.... On my system, pulse (and pulse/gconf-helper) run as unconfined_t. So does pidgin. But rhythmbox runs as unconfined_execmem_t. (This is needed for the fluendo mp3 codec, if I remember correctly). Could that "difference" (i.e., unconfined_t vs. unconfined_execmem_t) be "breaking" the code that checks shm? What does the code do? Check /proc/PID (or some such). Something like "lsof"?
To be frank I have no clue about SELinux except that it always breaks things and that Dan Walsh maintains some policy file that usually is broken. This is the code that does the cleanup: http://git.0pointer.de/?p=pulseaudio.git;a=blob;f=src/pulsecore/shm.c;h=b2997575d99cc91d2df966bf5573d0e804532eef;hb=HEAD#l321 (i.e. function pa_shm_cleanup()) We basically check with kill() that the PID stored in the shm seg can be killed (or when it cannot be killed that the error is not ESRCH).
Sorry, I still get this even when I boot in permissive mode (i.e., w/ enforcing=0): Sep 24 11:39:25 tlondon pulseaudio[3227]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Pidgin. Sep 24 11:39:25 tlondon pulseaudio[3227]: resampler.c: Using resampler 'speex-float-3' Sep 24 11:39:25 tlondon pulseaudio[3227]: resampler.c: Using float32le as working format. Sep 24 11:39:25 tlondon pulseaudio[3227]: resampler.c: Choosing speex quality setting 3. Sep 24 11:39:25 tlondon pulseaudio[3227]: sink-input.c: Created input 13 "Playback Stream" on alsa_output.pci_8086_27d8_sound_card_0_alsa_playback_0 with sample spec s16le 2ch 22050Hz and channel map front-left,front-right Sep 24 11:39:25 tlondon pulseaudio[3227]: protocol-native.c: Requested tlength=199.55 ms, minreq=9.98 ms Sep 24 11:39:25 tlondon pulseaudio[3227]: protocol-native.c: Final latency 379.14 ms = 179.59 ms + 2*9.98 ms + 179.59 ms Sep 24 11:39:27 tlondon pulseaudio[3227]: shm.c: shm_open() failed: No such file or directory Sep 24 11:39:27 tlondon pulseaudio[3227]: pstream.c: Failed to import memory block. Sep 24 11:39:27 tlondon pulseaudio[3227]: sink-input.c: Freeing input 13 "Playback Stream" Sep 24 11:39:27 tlondon pulseaudio[3227]: client.c: Freed 23 "Pidgin" Sep 24 11:39:27 tlondon pulseaudio[3227]: protocol-native.c: Connection died.
BTW, does the code handle the case of "wrapped" or reused pids? That is, the process that allocated the shm is dead, but the pid of the process is being used by another (unrelated) process? In that case, I think "kill(pid,0)==0" could be true, but the original process is really gone. Not this problem, I think, but it would fail to remove "dead" file.
Suppose another possibility is random number collision (pa_shm_create_rw): 131 pa_random(&m->id, sizeof(m->id)); 132 segment_name(fn, sizeof(fn), m->id); 133 134 if ((fd = shm_open(fn, O_RDWR|O_CREAT|O_EXCL, mode & 0444)) < 0) { 135 pa_log("shm_open() failed: %s", pa_cstrerror(errno)); 136 goto fail; 137 } Any chance pa_random() is producing collisons?
No, the code should be safe. The only risk is that we detect that an shm seg is still used but actually is not. i.e. we'd leak an shm seg for a bit longer than necessary. It is very unlikely that we hit random number collisions here. We use /dev/urandom to get the random number which should be a pretty ok RNG. And the number is 32bit wide. The chance to get collisions is thus about 1:80000, if I remember the birthday paradoxon correctly. It's not totally unlikely, but uh, you appear to be able to reproduce this more often then every 80k times? Hmm, I am really puzzled by this and cannot reproduce this here. The shm cleanup may be triggered directly via pulseaudio --cleanup-shm btw. Maybe you can use this to trigger the issue more quickly? Hmm, can I convince you to build the pa rpm yourself and disable them shm seg cleanup stuff while doing so? (i.e. simply put a "return 0" as the first like fo pa_shm_cleanup() in pulsecore/shhm.c.) If this problem persists we at least know that it is unrelated to the cleanup routine.
Hmm, I wonder if this is actually a race... i.e. the client sets up shm, connects to pa via socket, sends some data over the socket, closes the socket without waiting until it is okeyed, removes the shm. Then, PA comes, reads from the socket, tries to open the shm seg referred to in the data it just read. But the shm seg ain't there anymore. Is this always the sample client? i.e. Pidgin?
s/sample/same/ hehe, i guess that typo is a sign that i am doing too much audio stuff... ;-)
oh, and how is pidgin configured? what kind of audio output did you select?
Sure, you can convince me ;) I'll pull the rawhide source rpm and build. A few questions: 1. My quick reading of the code indicates that there are 2 places where this error might be generated: pa_shm_attach_ro() and pa_shm_create_rw(). I would usually make the error messages "unique", unless you are certain which leg of the code this is coming from. 2. The rawhide source rpm seems to want to build "the entire pulse world". Are all these binary packages needed to test this? To answer your questions: I believe I've only seen this with pidgin; but I almost always have rhythmbox running as well. So I'm guessing its pidgin+rhythmbox. Sound configuration of pidgin: I believe it is "stock" rawhide. Sound method says "Automatic", Enable sound when conversation has focus is selected, and Enable sound has "Only when available" selected. I'll play with the latter 2 options to see if I can get it to "do more sounds". And I'll set up a script/loop to run "pulseaudio --cleanup-shm" to see if I can trigger this more often. Haven't seen this in the last 2 days, BTW.
OK. Downloaded src rpm and the associated devel rpms. Building now. I applied the following patch to "disambiguate" the error message. --- pulseaudio-0.9.12/src/pulsecore/shm.c.orig 2008-22:06:10.000000000 -0400 +++ pulseaudio-0.9.12/src/pulsecore/shm.c 2008-09-15 22:08:39.000000000 -0400 @@ -132,7 +132,7 @@ segment_name(fn, sizeof(fn), m->id); if ((fd = shm_open(fn, O_RDWR|O_CREAT|O_EXCL, mode & 0444)) < 0) { - pa_log("shm_open() failed: %s", pa_cstrerror(errno)); + pa_log("pa_shm_create_rw(): shm_open() failed: %s", pa_cstrerror(errno)); goto fail; } @@ -273,7 +273,7 @@ if ((fd = shm_open(fn, O_RDONLY, 0)) < 0) { if (errno != EACCES) - pa_log("shm_open() failed: %s", pa_cstrerror(errno)); + pa_log("pa_shm_attach_ro(): shm_open() failed: %s", pa_cstrerror(errno)); goto fail; } When it completes building, I'll install and start testing.
I slightly modified the above patch adding some logging in the case the code unlinks a shm file. Patch below. I've been running this for about a day or so, but I have not yet been able to reproduce the issue. All day yesterday, I ran the following script as my normal user: while : do date pulseaudio --cleanup-shm echo; echo; echo; echo sleep 20 done >shm-log.txt 2>&1& Here are the last 2 outputs from '--cleanup-shm': Thu Oct 2 17:31:54 PDT 2008 I: caps.c: Limited capabilities successfully to CAP_SYS_NICE. I: caps.c: Dropping root priviliges. I: caps.c: Limited capabilities successfully to CAP_SYS_NICE. D: main.c: Started as real root: no, suid root: yes I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling. I: main.c: Giving up CAP_NICE D: main.c: Can realtime: yes, can high-priority: yes Thu Oct 2 17:32:14 PDT 2008 I: caps.c: Limited capabilities successfully to CAP_SYS_NICE. I: caps.c: Dropping root priviliges. I: caps.c: Limited capabilities successfully to CAP_SYS_NICE. D: main.c: Started as real root: no, suid root: yes I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling. I: main.c: Giving up CAP_NICE D: main.c: Can realtime: yes, can high-priority: yes W: shm.c: pa_shm_cleanup(): removing /pulse-shm-4185968735 W: shm.c: pa_shm_cleanup(): removing /pulse-shm-65240405 W: shm.c: pa_shm_cleanup(): removing /pulse-shm-144283580 W: shm.c: pa_shm_cleanup(): removing /pulse-shm-1194881054 This last is produced during "shutdown", otherwise there are no cleanup events logged. Not completely clear why this problem "stopped" or how to make it happen again (now that I'm watching....). I'll continue watching this today, but without the separate cleanup script. --- pulseaudio-0.9.12/src/pulsecore/shm.c.orig 2008-22:06:10.000000000 -0400 +++ pulseaudio-0.9.12/src/pulsecore/shm.c 2008-09-15 22:08:39.000000000 -0400 @@ -132,7 +132,7 @@ segment_name(fn, sizeof(fn), m->id); if ((fd = shm_open(fn, O_RDWR|O_CREAT|O_EXCL, mode & 0444)) < 0) { - pa_log("shm_open() failed: %s", pa_cstrerror(errno)); + pa_log("pa_shm_create_rw(): shm_open() failed: %s", pa_cstrerror(errno)); goto fail; } @@ -273,7 +273,7 @@ if ((fd = shm_open(fn, O_RDONLY, 0)) < 0) { if (errno != EACCES) - pa_log("shm_open() failed: %s", pa_cstrerror(errno)); + pa_log("pa_shm_attach_ro(): shm_open() failed: %s", pa_cstrerror(errno)); goto fail; } @@ -373,6 +373,9 @@ /* Ok, the owner of this shms segment is dead, so, let's remove the segment */ segment_name(fn, sizeof(fn), id); +#if 1 + pa_log_warn("pa_shm_cleanup(): removing %s\n", fn); +#endif if (shm_unlink(fn) < 0 && errno != EACCES && errno != ENOENT) pa_log_warn("Failed to remove SHM segment %s: %s\n", fn, pa_cstrerror(errno)); }
Running my modified version of pulseaudio (patch as in #23), I was not able to reproduce running my modified version of pulseaudio. Updated this morning to pulseaudio-libs-0.9.13-1.fc10.i386 pulseaudio-module-gconf-0.9.13-1.fc10.i386 pulseaudio-debuginfo-0.9.12-6.prep2.fc10.i386 [Yeah, I know this is the old version....] pulseaudio-libs-glib2-0.9.13-1.fc10.i386 pulseaudio-0.9.13-1.fc10.i386 pulseaudio-module-x11-0.9.13-1.fc10.i386 pulseaudio-core-libs-0.9.13-1.fc10.i386 pulseaudio-utils-0.9.13-1.fc10.i386 pulseaudio-esound-compat-0.9.13-1.fc10.i386 I'll continue to monitor with this version. If I see the stock warning, I'll apply patch, build, install and monitor..... I'm really trying to figure out what, if anything, changed in the last week or so to make this "stop happening". The "pulling at straws" hypothesis I came up with is nsplugin. I used to get random "alert notifications" from google messaging that slowed down this past week. Sorry I haven't been able to help out here.....
Created attachment 319752 [details] /var/log/messages segment showing "shm.c: shm_open() failed: No such file or directory" Scanning my logs, I got 2 more instances of this on 6 October while running "stock" pulseaudio-0.9.13-1.fc10.i386. I tried to include a larger context from /var/log/messages. Both occurred within a 6 or 7 minute interval.
Some more info and a question. I just brought up a new install from the F10-Spin CD on a Thinkpad X61 (versus the X60 I've been running). This system is running an X86_64 kernel (and apps). I did not see this problem running with this system for several days until just now: Oct 13 14:37:08 tlondon pulseaudio[3267]: shm.c: shm_open() failed: No such file or directory Oct 13 14:37:08 tlondon pulseaudio[3267]: pstream.c: Failed to import memory block. The most recent change I made was to change /etc/fstab to force /tmp to mount on a tmpfs (along with /dev/shm): tmpfs /tmp tmpfs defaults 0 0 tmpfs /dev/shm tmpfs defaults 0 0 I've run my older system with /tmp mounted on tmpfs for months, so the two systems are now the same (wrt /tmp). Don't suppose its possible that there is some sort of issue with 2 tmpfs? [Yeah, I know I'm pulling at straws....]
(In reply to comment #26) > Some more info and a question. > > I just brought up a new install from the F10-Spin CD on a Thinkpad X61 (versus > the X60 I've been running). > > This system is running an X86_64 kernel (and apps). > > I did not see this problem running with this system for several days until just > now: > > Oct 13 14:37:08 tlondon pulseaudio[3267]: shm.c: shm_open() failed: No such > file or directory > Oct 13 14:37:08 tlondon pulseaudio[3267]: pstream.c: Failed to import memory > block. > > The most recent change I made was to change /etc/fstab to force /tmp to mount > on a tmpfs (along with /dev/shm): > > tmpfs /tmp tmpfs defaults 0 0 > tmpfs /dev/shm tmpfs defaults 0 0 > > > I've run my older system with /tmp mounted on tmpfs for months, so the two > systems are now the same (wrt /tmp). > > Don't suppose its possible that there is some sort of issue with 2 tmpfs? > > [Yeah, I know I'm pulling at straws....] Consider this wrong. Sorry for the noise. (I still get this with only one tmpfs mount...) I get this
Uh? I don't see how this could be a blocker for F10?
Hi, I'm also seeing these here on my fully updated 64bit F9 system: Oct 24 16:23:51 localhost pulseaudio[2725]: shm.c: shm_open() failed: No such file or directory Oct 24 16:23:51 localhost pulseaudio[2725]: pstream.c: Failed to import memory block. When it happens, pulseaudio seems to get stuck. Video playing on totem on this situation causes video to progress very slowly, like 1 frame/s, and there's no sound at all. I'm not sure what exactly triggers this, but I'm usually listening to music on rhythmbox and doing some memory-intensive stuff on Eclipse (Java). Sometimes there might be some flash video playing on Firefox as well. "pulseaudio -k; pulseaudio -D" seems to fix the problem. System has 2GB RAM, pulseaudio is latest avaliable for F9 (pulseaudio-0.9.10-2.fc9.x86_64). Let me know if I can provide any additional info. BTW: I upgraded Flash to version 10, and I use nspluginwrapper and libflashsupport, but I read somewhere that it shouldn't be necessary with Flash 10 and actually might even cause problems. Should I drop libflashsupport?
This bug appears to have been reported against 'rawhide' during the Fedora 10 development cycle. Changing version to '10'. More information and reason for this action is here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
This message is a reminder that Fedora 10 is nearing its end of life. Approximately 30 (thirty) days from now Fedora will stop maintaining and issuing updates for Fedora 10. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as WONTFIX if it remains open with a Fedora 'version' of '10'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version prior to Fedora 10's end of life. Bug Reporter: Thank you for reporting this issue and we are sorry that we may not be able to fix it before Fedora 10 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora please change the 'version' of this bug to the applicable version. If you are unable to change the version, please add a comment here and someone will do it for you. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Fedora 10 changed to end-of-life (EOL) status on 2009-12-17. Fedora 10 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. Thank you for reporting this bug and we are sorry it could not be fixed.