Dear all,
I am running gnome 3.4 and pulse-audio 2.1.
When closing a window, gnome-shell sometimes hangs,
waiting for pulse-audio.
To reproduce:
Open a gnome-terminal, press backspace which produces a nice beep,
press the [X] in the window's title-bar.
Now the whole desktop is unresponsive (the cursor moves with the mouse,
but button presses are ignored).
This also happens with other applications (eg. firefox), and happens
both with pulse-audio debugging output turned on and off.
The GNU debugger (gdb) gives the following back-trace for gnome-shell:
------------------------------------------------------------
#0 0xb7735424 in __kernel_vsyscall ()
#1 0xb4ff26cd in pthread_cond_wait@@GLIBC_2.3.2 () at
../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/pthread_cond_wait.S:143
#2 0xb56aa26b in pa_cond_wait (c=0x9bc3ea0, m=0x9a53bd0) at
pulsecore/mutex-posix.c:139
#3 0xb570743e in pa_threaded_mainloop_wait (m=0x9bae118) at
pulse/thread-mainloop.c:206
#4 0xb35a54cb in pulse_driver_play (c=0x9b3c740, id=1,
proplist=0x954dd30, cb=0, userdata=0x0) at pulse.c:955
#5 0xb6f15733 in driver_play (c=c@entry=0x9b3c740, id=id@entry=1,
pl=pl@entry=0x954dd30, cb=cb@entry=0, userdata=userdata@entry=0x0) at
dso.c:342
#6 0xb6f0dff0 in ca_context_play_full (c=c@entry=0x9b3c740,
id=id@entry=1, p=0x954dd30, cb=cb@entry=0, userdata=userdata@entry=0x0)
at common.c:522
#7 0xb6f0e339 in ca_context_play (c=0x9b3c740, id=id@entry=1) at
common.c:462
#8 0xb74fb5eb in workspace_switch_sound (to=0x9efbaf0, from=0x9ef6338)
at core/workspace.c:496
#9 meta_workspace_activate_with_focus
(workspace=workspace@entry=0x9efbaf0, focus_this=focus_this@entry=0x0,
timestamp=timestamp@entry=0) at core/workspace.c:551
#10 0xb74fb73b in meta_workspace_activate
(workspace=workspace@entry=0x9efbaf0, timestamp=timestamp@entry=0) at
core/workspace.c:686
#11 0xb74df414 in meta_screen_remove_workspace (screen=0x911f8b8,
workspace=0x9ef6338, timestamp=0) at core/screen.c:1476
#12 0xb513f44e in ffi_call_SYSV () at ../src/x86/sysv.S:64
#13 0xb513f239 in ffi_call (cif=cif@entry=0xad020864, fn=0xb74df2a0
<meta_screen_remove_workspace>, rvalue=rvalue@entry=0xbfd7e154,
avalue=avalue@entry=0xbfd7e070) at ../src/x86/ffi.c:413
#14 0xb7455e57 in gjs_invoke_c_function
(context=context@entry=0x93ad578, function=0xad020858,
obj=obj@entry=0xabea1500, js_argc=js_argc@entry=2,
js_argv=js_argv@entry=0xac3ff0a8, js_rval=js_rval@entry=0xbfd7e278) at
gi/function.c:930
#15 0xb74575bd in function_call (context=0x93ad578, js_argc=2,
vp=0xac3ff098) at gi/function.c:1245
#16 0xb71dcb7c in js::Invoke(JSContext*, js::CallArgs const&, unsigned
int) () from //lib/libmozjs185.so.1.0
#17 0xb71c6082 in js::Interpret(JSContext*, JSStackFrame*, unsigned int,
JSInterpMode) () from //lib/libmozjs185.so.1.0
#18 0xb71dad04 in js::RunScript(JSContext*, JSScript*, JSStackFrame*) ()
from //lib/libmozjs185.so.1.0
#19 0xb71dca59 in js::Invoke(JSContext*, js::CallArgs const&, unsigned
int) () from //lib/libmozjs185.so.1.0
#20 0xb71dcf0c in js::ExternalInvoke(JSContext*, js::Value const&,
js::Value const&, unsigned int, js::Value*, js::Value*) () from
//lib/libmozjs185.so.1.0
#21 0xb7150056 in JS_CallFunctionValue () from //lib/libmozjs185.so.1.0
#22 0xb7455037 in gjs_callback_closure (cif=0x9f09160,
result=0xbfd7ea30, args=0xbfd7e9e0, data=0x9f09148) at gi/function.c:291
#23 0xb513f2f4 in ffi_closure_SYSV_inner (closure=0xabf5f1c0,
respp=0xbfd7ea3c, args=0xbfd7ea50) at ../src/x86/ffi.c:498
#24 0xb513f50a in ffi_closure_SYSV () at ../src/x86/sysv.S:188
#25 0xb74e6463 in run_repaint_laters (data=0x0) at core/util.c:794
#26 0xb65e52ed in _clutter_run_repaint_functions
(flags=flags@entry=CLUTTER_REPAINT_FLAGS_PRE_PAINT) at
./clutter-main.c:3572
#27 0xb65e77d4 in master_clock_update_stages (stages=0x9f020a8,
master_clock=0x9362d28) at ./clutter-master-clock.c:369
#28 clutter_clock_dispatch (source=source@entry=0x91475f0, callback=0,
user_data=0x0) at ./clutter-master-clock.c:519
#29 0xb5089de3 in g_main_dispatch (context=0x9121898) at gmain.c:2539
#30 g_main_context_dispatch (context=context@entry=0x9121898) at
gmain.c:3075
#31 0xb508a180 in g_main_context_iterate (context=0x9121898,
block=block@entry=1, dispatch=dispatch@entry=1, self=<error reading
variable: Unhandled dwarf expression opcode 0xfa>) at gmain.c:3146
#32 0xb508a5db in g_main_loop_run (loop=0x913d4c8) at gmain.c:3340
#33 0xb74d5c68 in meta_run () at core/main.c:555
#34 0x08049c87 in main (argc=1, argv=0xbfd7ed94) at main.c:334
------------------------------------------------------------
As far as I can see,
gnome-shell calls the mutter main loop,
which has clutter "repaint",
which in turns calls some JavaScript,
which ask canberra to play a sound,
and pulse-audio is trying to play the sound,
but hangs in a condition wait.
back-trace for pulseaudio:
------------------------------------------------------------
#0 0xb77be424 in __kernel_vsyscall ()
#1 0xb6fffa79 in ppoll (fds=0x8f049e0, nfds=23, timeout=<optimized
out>, sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:58
#2 0xb76e902b in pa_mainloop_poll (m=m@entry=0x8f03640) at
pulse/mainloop.c:881
#3 0xb76e97d9 in pa_mainloop_iterate (m=m@entry=0x8f03640,
block=block@entry=1, retval=retval@entry=0xbf9933d0) at
pulse/mainloop.c:955
#4 0xb76e98b4 in pa_mainloop_run (m=m@entry=0x8f03640,
retval=retval@entry=0xbf9933d0) at pulse/mainloop.c:973
#5 0x0804e1cc in main (argc=3, argv=0xbf9935a4) at daemon/main.c:1135
------------------------------------------------------------
The last 20 entries in the system log:
------------------------------------------------------------
[pulseaudio] module-suspend-on-idle.c: Sink
alsa_output.pci-0000_00_1e.2.analog-stereo becomes idle, timeout in 5
seconds.
[pulseaudio] module-suspend-on-idle.c: Sink
alsa_output.pci-0000_00_1e.2.analog-stereo becomes idle, timeout in 5
seconds.
[pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
[pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream
removed from object /org/pulseaudio/core1/playback_stream16
[pulseaudio] sink-input.c: Freeing input 16 "bell-window-system"
[alsa-sink] alsa-sink.c: Increasing wakeup watermark to 40.00 ms
[alsa-sink] ratelimit.c: 284 events suppressed
[alsa-sink] alsa-sink.c: Wakeup from ALSA!
[alsa-sink] alsa-sink.c: Underrun!
[alsa-sink] alsa-sink.c: Increasing wakeup watermark to 50.00 ms
[alsa-sink] alsa-sink.c: Wakeup from ALSA!
[alsa-sink] alsa-sink.c: Underrun!
[alsa-sink] alsa-sink.c: Increasing wakeup watermark to 60.00 ms
[pulseaudio] module-suspend-on-idle.c: Sink
alsa_output.pci-0000_00_1e.2.analog-stereo idle for too long, suspending
...
[pulseaudio] sink.c: Suspend cause of sink
alsa_output.pci-0000_00_1e.2.analog-stereo is 0x0004, suspending
[pulseaudio] flist.c: pulsecore/hashmap.c: entries flist is full (don't
worry)
[alsa-sink] alsa-sink.c: Device suspended...
[pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
[pulseaudio] reserve-wrap.c: Device lock status of
reserve-monitor-wrapper@Audio0 changed: not busy
[pulseaudio] module-udev-detect.c: /dev/snd/controlC0 is accessible: yes
------------------------------------------------------------
Any suggestions as to what the problem might be would be most
appreciated!
The above happens with KaarPux version 3.0.1.
KaarPux is a "linux from source" distro I am developing.
See http://kaarpux.kaarposoft.dk/
The bug report
http://sourceforge.net/p/kaarpux/tickets/2/
has full backtraces, straces and log information attached.
Thanks in advance for any help!
