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

Colin Guthrie gmane at colin.guthr.ie
Sat Nov 3 11:20:05 PDT 2012


'Twas brillig, and Henrik /KaarPoSoft at 10/09/12 21:13 did gyre and gimble:
> 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 at entry=0x9b3c740, id=id at entry=1,
> pl=pl at entry=0x954dd30, cb=cb at entry=0, userdata=userdata at entry=0x0) at
> dso.c:342
> #6  0xb6f0dff0 in ca_context_play_full (c=c at entry=0x9b3c740,
> id=id at entry=1, p=0x954dd30, cb=cb at entry=0, userdata=userdata at entry=0x0)
> at common.c:522
> #7  0xb6f0e339 in ca_context_play (c=0x9b3c740, id=id at 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 at entry=0x9efbaf0, focus_this=focus_this at entry=0x0,
> timestamp=timestamp at entry=0) at core/workspace.c:551
> #10 0xb74fb73b in meta_workspace_activate
> (workspace=workspace at entry=0x9efbaf0, timestamp=timestamp at 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 at entry=0xad020864, fn=0xb74df2a0
> <meta_screen_remove_workspace>, rvalue=rvalue at entry=0xbfd7e154,
> avalue=avalue at entry=0xbfd7e070) at ../src/x86/ffi.c:413
> #14 0xb7455e57 in gjs_invoke_c_function
> (context=context at entry=0x93ad578, function=0xad020858,
> obj=obj at entry=0xabea1500, js_argc=js_argc at entry=2,
> js_argv=js_argv at entry=0xac3ff0a8, js_rval=js_rval at 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 at 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 at 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 at entry=0x9121898) at
> gmain.c:3075
> #31 0xb508a180 in g_main_context_iterate (context=0x9121898,
> block=block at entry=1, dispatch=dispatch at 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 at entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:58
> #2  0xb76e902b in pa_mainloop_poll (m=m at entry=0x8f03640) at
> pulse/mainloop.c:881
> #3  0xb76e97d9 in pa_mainloop_iterate (m=m at entry=0x8f03640,
> block=block at entry=1, retval=retval at entry=0xbf9933d0) at
> pulse/mainloop.c:955
> #4  0xb76e98b4 in pa_mainloop_run (m=m at entry=0x8f03640,
> retval=retval at 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 at 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!

So this is technically from libcanberra which in turn uses PulseAudio to
output sound.

It seems it's waiting for the drain before exiting. The drain can take
longer than the sound for various boring reasons we won't go into just now.

Longer term the intention is to fix the drain behaviour such that
applications like canberra can exit much quicker, but I wonder if there
is something that can be done to cancel the wait for drain at the
canberra side when exiting.

Firstly thing to check I guess is that you're using the latest
libcanberra (0.29).

Cheers.

Col


-- 

Colin Guthrie
gmane(at)colin.guthr.ie
http://colin.guthr.ie/

Day Job:
  Tribalogic Limited http://www.tribalogic.net/
Open Source:
  Mageia Contributor http://www.mageia.org/
  PulseAudio Hacker http://www.pulseaudio.org/
  Trac Hacker http://trac.edgewall.org/


More information about the pulseaudio-discuss mailing list