[pulseaudio-discuss] gnome-shell hangs, waiting for pulse-audio

Mon Nov 26 07:42:37 PST 2012

On 11/26/12 14:30, Tanu Kaskinen wrote:
 > On Sun, 2012-11-25 at 22:25 +0200, Tanu Kaskinen wrote:
 >> So gnome-shell doesn't want to log to syslog? I've attached a pulseaudio
 >> patch that makes gnome-shell log to files under /tmp. Btw, I now noticed
 >> that running "gnome-shell --replace" restarts gnome-shell and makes the
 >> log from the new instance go to the current terminal.
 >
 > When I started my computer today, I found out that the patch causes a
 > segfault during the gnome session startup, so X wouldn't come up. I've
 > attached a fixed patch. Another note is that the patch doesn't work for
 > the initial instance of gnome-shell. I'd guess that's because the "_"
 > environment variable isn't set during the session startup. The patch
 > should probably read the executable from /proc/self/cmdline rather than
 > the "_" environment variable. I can do that change if necessary, but
 > given that "gnome-shell --replace" works for getting the log anyway,
 > maybe the whole patch is unnecessary.
 >

Tanu, again: Thanks for your help.

I tried the patch and various other changes to log.c, but getting no 
useful logging, and sometimes segfaults instead (as you also noted).

My mind kept coming back to this:

ldd /bin/gnome-shell | grep pulse
     libpulse-mainloop-glib.so.0 => //lib/libpulse-mainloop-glib.so.0 
(0xb5771000)
     libpulse.so.0 => //lib/libpulse.so.0 (0xb5723000)
     libpulsecommon-2.1.so => //lib/pulseaudio/libpulsecommon-2.1.so 
(0xb56b7000)
     libpulsecommon-2.99.so => //lib/pulseaudio/libpulsecommon-2.99.so 
(0xb4da6000)

So, I deleted every file installed by the original pulseaudio 2.1, 
recompiled+installed pulseaudio 2.99.2, and recompiled+installed 
gnome-shell.

Now I have:

ldd /bin/gnome-shell | grep pulse
     libpulse-mainloop-glib.so.0 => //lib/libpulse-mainloop-glib.so.0 
(0xb56e3000)
     libpulse.so.0 => //lib/libpulse.so.0 (0xb5695000)
     libpulsecommon-2.99.so => //lib/pulseaudio/libpulsecommon-2.99.so 
(0xb5620000)

(A quick look at gnome-shell source did not reveal why it would link to 
an old version; I must have a closer look at this later).

And the good news:
Now the clients (incl gnome-shell) are showing the "Received opcode" in 
~/.xsession-errors (presumably because they log to stderr which is 
redirected to ~/.xsession-errors).

And the even better news:
I have tried to recreate the freeze without success.
So, maybe 2.99.2 solved the original problem after all.

However, I am still having some trouble...

Syslog show as lot (about 5/sec to 10/sec) entries like:
Nov 26 16:31:04 kx8400-5 pulseaudio[2078]: (1745.440|   0.057) 
[pulseaudio] pdispatch.c: [0x9ee32f0] Received opcode 
<GET_PLAYBACK_LATENCY>, tag 1088
And ~/.xsession-errors shows the corresponding
Received opcode <REPLY>

I am not sure if this is a problem or not, but previously I did not 
notice such pulseaudio bursts in syslog.

Further thunderbird crashes every now and then (maybe not related, but 
it never did that before),
and sometimes the terminal does not beep as expected.

For the latter case (terminal does not beep as expected) I have this in 
syslog:

------------------------------------------------------------
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.550|   0.000) 
[pulseaudio] pdispatch.c: [0x9f6f018] Received opcode <AUTH>, tag 0
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.550|   0.000) 
[pulseaudio] protocol-native.c: Protocol version: remote 27, local 27
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.550|   0.000) 
[pulseaudio] protocol-native.c: Got credentials: uid=2002 gid=2000 success=1
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.550|   0.000) 
[pulseaudio] protocol-native.c: SHM possible: yes
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.550|   0.000) 
[pulseaudio] protocol-native.c: Negotiated SHM: yes
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.551|   0.000) 
[pulseaudio] pdispatch.c: [0x9f6f018] Received opcode <SET_CLIENT_NAME>, 
tag 1
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.551|   0.000) 
[pulseaudio] module-augment-properties.c: Looking for .desktop file for 
gnome-shell
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.553|   0.001) 
[pulseaudio] pdispatch.c: [0x9f6f018] Received opcode 
<CREATE_PLAYBACK_STREAM>, tag 2
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.553|   0.000) 
[pulseaudio] module-intended-roles.c: Not setting device for stream ALSA 
Playback, because it lacks role.
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.553|   0.000) 
[pulseaudio] module-suspend-on-idle.c: Sink 
alsa_output.pci-0000_00_1e.2.analog-stereo becomes busy.
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.553|   0.000) 
[pulseaudio] sink-input.c: Failed to create sink input: too many inputs 
per sink.
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.554|   0.001) 
[pulseaudio] client.c: Freed 92 "ALSA plug-in [gnome-shell]"
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.556|   0.001) 
[pulseaudio] protocol-native.c: Connection died.
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.559|   0.003) 
[pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client 
removed from object /org/pulseaudio/core1/client92
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.560|   0.001) 
[pulseaudio] pdispatch.c: [0x9e9b1d0] Received opcode <GET_CLIENT_INFO>, 
tag 391
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.563|   0.002) 
[pulseaudio] pdispatch.c: [0x9e9b1d0] Received opcode <GET_CLIENT_INFO>, 
tag 392
Nov 26 16:35:30 kx8400-5 pulseaudio[2078]: (2011.626|   0.063) 
[pulseaudio] pdispatch.c: [0x9ee83f8] Received opcode 
<GET_PLAYBACK_LATENCY>, tag 1263
------------------------------------------------------------

And this in ~/.xsession-errors

------------------------------------------------------------
[0xaaa64f60] Received opcode <REPLY>, tag 1135
[0xaa935d68] Received opcode <REPLY>, tag 0
[0xaa935d68] Received opcode <REPLY>, tag 1
[0xaa935d68] Received opcode <ERROR>, tag 2
ALSA lib pcm_pulse.c:750:(pulse_prepare) PulseAudio: Unable to create 
stream: Too large
[0x91d5600] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295
[0x91d5600] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295
[0xafcc9858] Received opcode <REPLY>, tag 1263
[0x91d5600] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295
[0x91d5600] Received opcode <ERROR>, tag 391
[0x91d5600] Received opcode <ERROR>, tag 392
[0xaaaf89d8] Received opcode <REPLY>, tag 1137
[0x7c9dca20] Received opcode <REPLY>, tag 1262
[0xafc10bd0] Received opcode <REPLY>, tag 1318
[0xafc60e08] Received opcode <REPLY>, tag 1265
[0xafc2dfd8] Received opcode <REPLY>, tag 1276
[0xaaa77590] Received opcode <REPLY>, tag 1263
[0xafc9fe38] Received opcode <REPLY>, tag 1265
[0x7c9917f8] Received opcode <REPLY>, tag 1258
[0x7c9b04b0] Received opcode <REPLY>, tag 1261
[0xafcbec60] Received opcode <REPLY>, tag 1265
[0xaa83e068] Received opcode <REPLY>, tag 1134
[0x7c9dbd80] Received opcode <REPLY>, tag 1260
[0x7c9727f0] Received opcode <REPLY>, tag 1263
------------------------------------------------------------

/Henrik