<html> <head> <meta content="text/html; charset=UTF-8" http-equiv="Content-Type"> </head> <body bgcolor="#FFFFFF" text="#000000"> <div class="moz-text-flowed" style="font-family: -moz-fixed; font-size: 12px;" lang="x-unicode">On 12/02/12 05:49, Tanu Kaskinen wrote: <blockquote type="cite" style="color: #000000;">On Wed, 2012-11-28 at 02:35 +0100, Henrik /KaarPoSoft wrote: <blockquote type="cite" style="color: #000000;"> It seems that more apps / libraries depend on libpulsecommon-2.1.so which has now been removed (as 2.99.2 has been installed instead). So, I tried to identify every lib/app dependent on pulseaudio, and have now recompiled+reinstalled: gnome-shell alsa-plugins libcanberra gst-plugins-good gnome-control-center gnome-settings-daemon gtk-vnc empathy Now I am *not* able to recreate this hang: open gnome-terminal (as only app on desktop), press backspace, close terminal. However, this seems to hang every time: open gnome-terminal, press backspace twice to get two beeps. open firefox, play html5 video on youtube, close firefox. close gnome-terminal (which is now last app on desktop). Now the desktop is frozen. The last 40 lines of .xsession-errors: ---------------------------------------- [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0x9e6df4f0] Received opcode <REQUEST>, tag 4294967295 [0xb2406210] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x9e6df4f0] Received opcode <REPLY>, tag 25 [0x9e6df4f0] Received opcode <REPLY>, tag 26 [0xa643cd8] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x9e6df4f0] Received opcode <REPLY>, tag 27 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x9e6df4f0] Received opcode <REPLY>, tag 28 [0x877c6e0] Received opcode <REPLY>, tag 35 [0x877c6e0] Received opcode <REPLY>, tag 36 [0xa643cd8] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x9e6df4f0] Received opcode <REPLY>, tag 29 [0xa643cd8] Received opcode <REPLY>, tag 26 [0xa643cd8] Received opcode <REPLY>, tag 27 [0x9e6df4f0] Received opcode <REPLY>, tag 30 [0x9e6df4f0] Received opcode <REPLY>, tag 31 [0x9e6df4f0] Received opcode <REPLY>, tag 32 [0x9e6df4f0] Received opcode <REPLY>, tag 33 [0x9e6df4f0] Received opcode <REPLY>, tag 34 [0x9e6df4f0] Received opcode <REPLY>, tag 35 [0x9e6df4f0] Received opcode <REPLY>, tag 36 [0x9e6df4f0] Received opcode <REPLY>, tag 37 [0x9e6df4f0] Received opcode <REPLY>, tag 38 [0xb2406210] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0xa643cd8] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0xa643cd8] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0xb2406210] Received opcode <ERROR>, tag 9 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x877c6e0] Received opcode <SUBSCRIBE_EVENT>, tag 4294967295 [0x877c6e0] Received opcode <REPLY>, tag 37 [0x877c6e0] Received opcode <REPLY>, tag 38 ---------------------------------------- The last 20 lines of syslog matching grep 'Received opcode' ---------------------------------------- Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.665| 0.001) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 27 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.675| 0.009) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x8666228] Received opcode <GET_SINK_INPUT_INFO>, tag 35 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.676| 0.001) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x86812c0] Received opcode <GET_SINK_INPUT_INFO>, tag 26 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.677| 0.001) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 28 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.678| 0.001) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x8666228] Received opcode <GET_SINK_INFO>, tag 36 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.694| 0.015) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 29 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.705| 0.011) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x86812c0] Received opcode <GET_SINK_INFO>, tag 27 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.734| 0.029) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 30 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.815| 0.081) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 31 Nov 28 02:05:54 kx8400-5 pulseaudio[2064]: ( 52.976| 0.160) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 32 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.297| 0.320) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 33 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.325| 0.028) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 34 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.327| 0.001) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <CORK_PLAYBACK_STREAM>, tag 35 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.327| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 36 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.328| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 37 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.328| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <FLUSH_PLAYBACK_STREAM>, tag 38 Nov 28 02:05:55 kx8400-5 pulseaudio[2064]: ( 53.328| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x868dcc8] Received opcode <GET_PLAYBACK_LATENCY>, tag 39 Nov 28 02:05:56 kx8400-5 pulseaudio[2064]: ( 54.319| 0.052) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x86828d8] Received opcode <PLAY_SAMPLE>, tag 9 Nov 28 02:06:00 kx8400-5 pulseaudio[2064]: ( 58.343| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x8666228] Received opcode <GET_SINK_INFO>, tag 37 Nov 28 02:06:00 kx8400-5 pulseaudio[2064]: ( 58.343| 0.000) [pulseaudio][pulsecore/pdispatch.c:318 pa_pdispatch_run()] [0x8666228] Received opcode <GET_SOURCE_INFO>, tag 38 ---------------------------------------- So it would seem that tag 39 is received by pulseaudio daemon, but the response not received by the client (presumably gnome-shell) </blockquote> Do you mean the reply to the GET_PLAYBACK_LATENCY message? If this is the exact same code that is hanging in the original backtrace, then the latency message isn't the problem. Also, the latency message comes from a different client than the PLAY_SAMPLE message, so the latency message is probably not from gnome-shell. </blockquote> I concur. I think that #39 GET_PLAYBACK_LATENCY is from firefox, which was closed, hence not receiving the result. <blockquote type="cite" style="color: #000000;">Assuming that it is always the PLAY_SAMPLE message that hangs, then it looks like the reply is received by the client. The last PLAY_SAMPLE message has tag 9, and xsession-errors shows that some client receives an error reply for tag 9 (an error is expected, because we found out already earlier that there are always two PLAY_SAMPLE messages, of which the latter one fails). </blockquote> I concur. <blockquote type="cite" style="color: #000000;">The original backtrace only has the trace for one thread, the thread where the libpulse mainloop runs isn't shown. Could you take a backtrace again, this time with "thread apply all bt"? The libpulse thread might be hanging too (which would explain why the main thread is hanging, since the libpulse thread is responsible for waking up the main thread). </blockquote> I have changed Xsession to log client messages to syslog. Unfortunatly they all show up with tag Xsession, not the individual client. Anyway, I have attached the relevant part of syslog (pulseaudio and Xsession), as well as pulseaudio and gnome-shell backtraces for all threads. <blockquote type="cite" style="color: #000000;">Btw, when it hangs, does it hang permanently, needing gnome-shell restart? </blockquote> Permanently, as in at least 10 minutes. (I don't wait that long every time, but I did a couple of times, and nothing changed within 10-15 minutes). So yes: Needing restart. (I usually do a reboot to get a clean slate, but somtimes I just restart gdm. Have not tried just gnome.shell restart). <blockquote type="cite" style="color: #000000;">Lastly, when pasting syslog contents, please ensure that the lines aren't wrapped. It's really hard to read otherwise. </blockquote> My apologies. Will use attachments. /Henrik Now attaching syslog+backtraces tar+gzipped; previous message was rejected; apologies if you receive this twice. </div> </body> </html>