Comment 1 for bug 1436162

Revision history for this message
Ricardo Salveti (rsalveti) wrote :

The mutex in question is the one used by pulse's mainloop, which gets used by pa_threaded_mainloop_lock, pa_threaded_mainloop_unlock and pa_threaded_mainloop_wait.

As the pulseaudio calls are all asynchronous, gst (pulsesink element) calls pa_threaded_mainloop_wait right after calling pulseaudio, so it can block the thread until pulseaudio returns via callback (which then calls pa_threaded_mainloop_signal, unblocking the thread).

The mutex is also recursive, allowing many lock and unlock calls to happen in parallel.

Follows the log when I'm able to reproduce the crash (with the mutex recursive count):
Interrupt: Stopping pipeline ...
Execution ended after 0:00:06.840520615
Setting pipeline to PAUSED ...
(thread id: 3069599744) pa_threaded_mainloop_lock -> mutex: 0xb5250e00
(thread id: 3069599744) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3069599744) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3069599744) pa_threaded_mainloop_unlock -> mutex: 0xb5250e00
(thread id: 3069599744) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3069599744) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
0:00:07.586470308 12439 0x15d1dc0 DEBUG pulse pulsesink.c:1272:gst_pulseringbuffer_pause:<pulsesink1> Pausing and corking, before calling mainloop lock
(thread id: 3069599744) pa_threaded_mainloop_lock -> mutex: 0xb5250e00
(thread id: 3069599744) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3069599744) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
0:00:07.586854770 12439 0x15d1dc0 DEBUG pulse pulsesink.c:1135:gst_pulsering_set_corked:<pulsesink1> Setting corked state to 1
0:00:07.587025308 12439 0x15d1dc0 DEBUG pulse pulsesink.c:1142:gst_pulsering_set_corked:<pulsesink1> Calling pa_threaded_mainloop_wait (PA_OPERATION_RUNNING)
(thread id: 3069599744) pa_threaded_mainloop_wait -> cond: 0xb52517b8, mutex: 0xb5250e00
(thread id: 3069599744) pa_cond_wait -> m: 0xb5250e00 (count before wait 1)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func lock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count prev 0)
(thread id: 3018630240) pa_mutex_lock -> m: 0xb5250e00 (count new 1)
(thread id: 3018630240) pa_threaded_mainloop_signal -> cond: 0xb52517b8, wait_for_accept: 0, n_waiting: 2
(thread id: 3018630240) pa_cond_signal broadcast -> c 0xb52517b8)
(thread id: 2941641824) pa_cond_wait -> m: 0xb5250e00 (count after wait 1)
(thread id: 2941641824) pa_threaded_mainloop_unlock -> mutex: 0xb5250e00
(thread id: 2941641824) pa_mutex_unlock -> m: 0xb5250e00 (count prev 1)
(thread id: 2941641824) pa_mutex_unlock -> m: 0xb5250e00 (count new 0)
(thread id: 3018630240) poll_func unlock -> mutex: 0xb5250e00
(thread id: 3018630240) pa_mutex_unlock -> m: 0xb5250e00 (count prev 0)
Assertion 'pthread_mutex_unlock(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:118, function pa_mutex_unlock(). Aborting.
Aborted (core dumped)