[Bug 493162] New: pidgin hangs on pulseaudio

http://bugzilla.novell.com/show_bug.cgi?id=493162 Summary: pidgin hangs on pulseaudio Classification: openSUSE Product: openSUSE 11.1 Version: Final Platform: i686 OS/Version: openSUSE 11.1 Status: NEW Severity: Normal Priority: P5 - None Component: X11 Applications AssignedTo: bnc-team-screening@forge.provo.novell.com ReportedBy: ptesarik@novell.com QAContact: qa@suse.de Found By: L3 Occasionally, pidgin hangs. I can't reproduce it Last time it did, I attached to the hung process with gdb, and this is what I see: * 1 Thread 0xb6ee9ab0 (LWP 5513) 0xb7f74424 in __kernel_vsyscall () 2 Thread 0xae2feb90 (LWP 5995) 0xb7f74424 in __kernel_vsyscall () 3 Thread 0xb3301b90 (LWP 5994) 0xb7f74424 in __kernel_vsyscall () 4 Thread 0xaeaffb90 (LWP 5993) 0xb7f74424 in __kernel_vsyscall () 5 Thread 0xb3d53b90 (LWP 5992) 0xb7f74424 in __kernel_vsyscall () Please read on! This is not a pure backtrace. This is a commented backtrace. [Switching to thread 1 (Thread 0xb6ee9ab0 (LWP 5513))] #0 0xb7f74424 in __kernel_vsyscall () #1 0xb70f882d in pthread_mutex_lock () from /lib/libpthread.so.0 int pthread_mutex_lock(pthread_mutex_t *mutex); mutex = 0xb3408590 *mutex = {__data = {__lock = 0x8000176b, __count = 1, __owner = 5995, /* Thread 2 */ __kind = 0x21, __nusers = 1, {__spins = 0x0, __list = {__next = 0x0}}}, __size = {0x6b, 0x17, 0x0, 0x80, 0x1, 0x0, 0x0, 0x0, 0x6b, 0x17, 0x0, 0x0, 0x21, 0x0, 0x0, 0x0, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, __align = 0x8000176b} #2 0xb334eaa1 in pa_mutex_lock (m=0xb3408590) at pulsecore/mutex-posix.c:90 #3 0xb3326530 in pa_threaded_mainloop_lock (m=0xb34032a0) at pulse/thread-mainloop.c:172 #4 0xb3541e08 in ?? () from /usr/lib/gstreamer-0.10/libgstpulse.so ^^ Debuginfo is insufficient here, but looking at the caller, I can see that this was called like this: 0xb3d78f8e mov 0x19c(%edi),%eax 0xb3d78f94 mov %esi,(%esp) 0xb3d78f97 call *%eax The value of %edi is saved on stack immediately after the return address (and is 0xba34b460), so the function is at: (gdb) x/x 0xba34b460+0x19c 0xba34b5fc: 0xb3541dd0 0xb3541dd0 push %ebp 0xb3541dd1 mov %esp,%ebp 0xb3541dd3 push %edi 0xb3541dd4 push %esi 0xb3541dd5 push %ebx 0xb3541dd6 call 0xb353e737 0xb3541ddb add $0x9219,%ebx <------- So, GOT is 0xb354aff4 .. 0xb3541e71 lea -0x2f86(%ebx),%eax ---> "gst_pulsesink_reset" 0xb3541e77 mov %eax,-0x3c(%ebp) (this is the 'function' argument to gst_debug_log, which expands via CHECK_DEAD_GOTO and GST_ELEMENT_ERROR and GST_FUNCTION to __FUNCTION__, so it's pretty certain that this is indeed gst_pulsesink_reset.) #5 0xb3d78f99 in gst_audioringbuffer_pause (buf=0xb3405508) at gstaudiosink.c:461 #6 0xb3d8526f in gst_ring_buffer_pause_unlocked (buf=0xb3405508) at gstringbuffer.c:930 #7 0xb3d8677f in gst_ring_buffer_pause (buf=0xb3405508) at gstringbuffer.c:973 #8 0xb3d818e4 in gst_base_audio_sink_change_state (element=0xba350898, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbaseaudiosink.c:1658 #9 0xb7ec48b8 in gst_element_change_state (element=0xba350898, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #10 0xb7ec77fc in gst_element_set_state_func (element=0xba350898, state=GST_STATE_PAUSED) at gstelement.c:2377 #11 0xb7ec3ae2 in gst_element_set_state (element=0xba350898, state=GST_STATE_PAUSED) at gstelement.c:2280 #12 0xb7eb50ba in gst_bin_change_state_func (element=0xba34a0f8, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbin.c:1932 #13 0xb354dfeb in ?? () from /usr/lib/gstreamer-0.10/libgstautodetect.so #14 0xb7ec48b8 in gst_element_change_state (element=0xba34a0f8, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #15 0xb7ec77fc in gst_element_set_state_func (element=0xba34a0f8, state=GST_STATE_PAUSED) at gstelement.c:2377 #16 0xb7ec3ae2 in gst_element_set_state (element=0xba34a0f8, state=GST_STATE_PAUSED) at gstelement.c:2280 #17 0xb7eb50ba in gst_bin_change_state_func (element=0xba342348, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbin.c:1932 #18 0xb7ec48b8 in gst_element_change_state (element=0xba342348, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #19 0xb7ec77fc in gst_element_set_state_func (element=0xba342348, state=GST_STATE_PAUSED) at gstelement.c:2377 #20 0xb7ec3ae2 in gst_element_set_state (element=0xba342348, state=GST_STATE_PAUSED) at gstelement.c:2280 #21 0xb7eb50ba in gst_bin_change_state_func (element=0xba313168, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbin.c:1932 #22 0xb5b0e190 in ?? () from /usr/lib/gstreamer-0.10/libgstgconfelements.so #23 0xb5b0aff6 in ?? () from /usr/lib/gstreamer-0.10/libgstgconfelements.so #24 0xb7ec48b8 in gst_element_change_state (element=0xba313168, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #25 0xb7ec77fc in gst_element_set_state_func (element=0xba313168, state=GST_STATE_PAUSED) at gstelement.c:2377 #26 0xb7ec3ae2 in gst_element_set_state (element=0xba313168, state=GST_STATE_PAUSED) at gstelement.c:2280 #27 0xb7eb50ba in gst_bin_change_state_func (element=0xba2e3b58, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbin.c:1932 #28 0xb7ec48b8 in gst_element_change_state (element=0xba2e3b58, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #29 0xb7ec77fc in gst_element_set_state_func (element=0xba2e3b58, state=GST_STATE_PAUSED) at gstelement.c:2377 #30 0xb7ec3ae2 in gst_element_set_state (element=0xba2e3b58, state=GST_STATE_PAUSED) at gstelement.c:2280 #31 0xb7eb50ba in gst_bin_change_state_func (element=0xba30f228, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstbin.c:1932 #32 0xb7ee68fa in gst_pipeline_change_state (element=0xba30f228, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstpipeline.c:463 #33 0xb3dfa101 in gst_play_base_bin_change_state (element=0xba30f228, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstplaybasebin.c:2729 #34 0xb3dea8bd in gst_play_bin_change_state (element=0xba30f228, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstplaybin.c:1932 #35 0xb7ec48b8 in gst_element_change_state (element=0xba30f228, transition=GST_STATE_CHANGE_PLAYING_TO_PAUSED) at gstelement.c:2427 #36 0xb7ec77fc in gst_element_set_state_func (element=0xba30f228, state=GST_STATE_NULL) at gstelement.c:2377 #37 0xb7ec3ae2 in gst_element_set_state (element=0xba30f228, state=GST_STATE_NULL) at gstelement.c:2280 #38 0xb803f06c in bus_call (bus=0xb9f406d8, msg=0xba2fb350, data=0xba30f228) at gtksound.c:372 #39 0xb7eb9186 in gst_bus_source_dispatch (source=0xba336d18, callback=0xb803efb0 , user_data=0xba30f228) at gstbus.c:783 #40 0xb719d9a8 in IA__g_main_context_dispatch (context=0xb9cd66d0) at gmain.c:2144 #41 0xb71a1063 in g_main_context_iterate (context=0xb9cd66d0, block=1, dispatch=1, self=0xb9caf3e8) at gmain.c:2778 #42 0xb71a1582 in IA__g_main_loop_run (loop=0xba0f5918) at gmain.c:2986 #43 0xb7b61239 in gtk_main () from /usr/lib/libgtk-x11-2.0.so.0 #44 0xb801a19e in main (argc=Cannot access memory at address 0x1 ) at gtkmain.c:888 [Switching to thread 2 (Thread 0xae2feb90 (LWP 5995))] #0 0xb7f74424 in __kernel_vsyscall () #1 0xb70fd7b9 in __lll_lock_wait () from /lib/libpthread.so.0 #2 0xb70f8cd1 in _L_lock_89 () from /lib/libpthread.so.0 #3 0xb70f85b2 in pthread_mutex_lock () from /lib/libpthread.so.0 int pthread_mutex_lock(pthread_mutex_t *mutex); mutex = 0xb34087d8 *mutex = {__data = {__lock = 2, __count = 0, __owner = 5513, __kind = 0x0, /* Thread 1 */ __nusers = 1, {__spins = 0x0, __list = {__next = 0x0}}}, __size = {0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x89, 0x15, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, __align = 0x2} #4 0xb7eaceff in gst_object_get_name (object=0xba350898) at gstobject.c:702 #5 0xb7ead112 in gst_object_get_path_string (object=0xba350898) at gstobject.c:1103 #6 0xb7ec5060 in gst_element_message_full (element=0xba350898, type=GST_MESSAGE_ERROR, domain=2254, code=1, text=0xb9dedd68 "Disconnected: Connection terminated", debug=0x0, file=0xb3547a2b "pulsesink.c", function=0xb3548096 "gst_pulsesink_write", line=536) at gstelement.c:1663 #7 0xb3542c07 in ?? () from /usr/lib/gstreamer-0.10/libgstpulse.so ^^ The 'function' argument to gst_element_message_full() identifies this as gst_pulsesink_write. #8 0xb3d7968c in audioringbuffer_thread_func (buf=0xb3405508) at gstaudiosink.c:226 #9 0xb71c835f in g_thread_create_proxy (data=0xb9df7e18) at gthread.c:635 #10 0xb70f71b5 in start_thread () from /lib/libpthread.so.0 #11 0xb70663be in clone () from /lib/libc.so.6 The other threads are not relevant AFAICS. To recap, Thread 1 waits for a mutex held by Thread 2, and Thread 2 waits for a mutex held by Thread 1. A classical ABBA deadlock. One possible sequence of events was: Thread 1: acquire the audio sink object lock I do not know where this happened, sorry. But the owner of the lock is thread 1, so it must have happened. Thread 2: acquire pulsesink->mainloop via pa_threaded_mainloop_lock() Thread 1: try to acquire pulsesink->mainloop via pa_threaded_mainloop_lock() But it is held by Thread 2, so wait here. Thread 2: deadlock on object lock via GST_OBJECT_LOCK () This gets called via GST_ELEMENT_ERROR -> gst_element_message_full -> gst_object_get_path_string -> gst_object_get_name Note that this analysis may also help with bug 442466, but that one is reported against SLED11. -- Configure bugmail: http://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.