After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 736071 - audiobasesink: Don't hold object lock while calling into other objects like the clock
audiobasesink: Don't hold object lock while calling into other objects like t...
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-good
1.2.1
Other Linux
: Normal blocker
: 1.4.4
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks: 739025
 
 
Reported: 2014-09-04 16:42 UTC by aksg86
Modified: 2014-10-22 17:53 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Possible fix to the problem. Release object lock on sink before calling gst_audio_clock_get_time. (1.00 KB, patch)
2014-09-04 16:54 UTC, aksg86
needs-work Details | Review
New Patch after suggested changes. (3.24 KB, patch)
2014-09-05 17:09 UTC, aksg86
none Details | Review
Please look at this one for review. Thanks. (3.21 KB, patch)
2014-09-05 21:43 UTC, aksg86
committed Details | Review
pulsesink: Make emitting stream status messages synchronous (1.98 KB, patch)
2014-09-29 14:57 UTC, Arun Raghavan
none Details | Review
pulsesink: Make emitting stream status messages synchronous (2.52 KB, patch)
2014-09-30 00:58 UTC, Arun Raghavan
committed Details | Review
pulsesink: Temporarily disable stream status posting (3.52 KB, patch)
2014-10-22 17:42 UTC, Arun Raghavan
committed Details | Review

Description aksg86 2014-09-04 16:42:33 UTC
At times while doing the Pipeline state transition from PAUSED to PLAYING i see a deadlock between the PulseAudio Main Loop thread and AudioBaseSink Render thread. 

The PA thread holds the pulseaudio mainloop lock and is trying 
to obtain the pulsesink element lock in a call to gst_element_post_message_default(). 

The AudioBaseSink render thread holds the pulsesink element lock and is trying to obtain the pulseaudio mainloop lock in a call to gst_pulsesink_get_time(). 

Stack-trace of the 2 threads: 

Thread 1
  • #0 __lll_lock_wait
    at ../ports/sysdeps/unix/sysv/linux/arm/nptl/lowlevellock.c line 49
  • #1 __pthread_mutex_lock
    at pthread_mutex_lock.c line 101
  • #2 g_mutex_lock
    at gthread-posix.c line 208
  • #3 gst_element_post_message_default
    at gstelement.c line 1677
  • #4 gst_element_post_message
    at gstelement.c line 1728
  • #5 mainloop_enter_defer_cb
    at pulsesink.c line 1135
  • #6 once_callback
    at pulse/mainloop-api.c line 47
  • #7 dispatch_defer
    at pulse/mainloop.c line 682
  • #8 pa_mainloop_dispatch
    at pulse/mainloop.c line 895
  • #9 pa_mainloop_iterate
    at pulse/mainloop.c line 935
  • #10 pa_mainloop_run
    at pulse/mainloop.c line 950
  • #11 thread
    at pulse/thread-mainloop.c line 88
  • #12 internal_thread_func
    at pulsecore/thread-posix.c line 83
  • #13 start_thread
    at pthread_create.c line 306
  • #14 clone
    from /rfs/lib/libc.so.6
  • #0 __pthread_mutex_lock_full
    at pthread_mutex_lock.c line 303
  • #1 pa_mutex_lock
    at pulsecore/mutex-posix.c line 90
  • #2 gst_pulsesink_get_time
    at pulsesink.c line 1935
  • #3 gst_audio_clock_get_time
    at gstaudioclock.c line 228
  • #4 gst_audio_base_sink_sync_latency
    at gstaudiobasesink.c line 1448
  • #5 gst_audio_base_sink_render
    at gstaudiobasesink.c line 1628


Possible fix (maybe):

In gst_audio_base_sink_skew_slaving inside gst-plugins-base/gst-libs/gst/audio/gstaudiobasesink.c we call gst_audio_clock_get_time on sink->provided_clock without acquiring the GST_OBJECT_LOCK(sink). Likewise in gst_audio_base_sink_setcaps. Can we do the same in this case also?

Something like in the attached patch.
Comment 1 aksg86 2014-09-04 16:54:08 UTC
Created attachment 285401 [details] [review]
Possible fix to the problem. Release object lock on sink before calling gst_audio_clock_get_time.
Comment 2 Sebastian Dröge (slomo) 2014-09-05 08:06:54 UTC
Review of attachment 285401 [details] [review]:

Can you attach the patch in "git format-patch" format?

::: gst-libs/gst/audio/gstaudiobasesink.c
@@ +1482,1 @@
   itime = gst_audio_clock_adjust (sink->provided_clock, itime);

Move the "etime = ..." line below this, and keep the lock unlocked for both "itime = ..." lines. Releasing the lock here seems safe considering the other code using the clock and the code above these lines
Comment 3 aksg86 2014-09-05 17:09:33 UTC
Created attachment 285511 [details] [review]
New Patch after suggested changes.
Comment 4 aksg86 2014-09-05 17:12:40 UTC
Review of attachment 285401 [details] [review]:

Please take a look at the new patch. Thanks for your review.
Comment 5 aksg86 2014-09-05 21:43:56 UTC
Created attachment 285529 [details] [review]
Please look at this one for review. Thanks.

Updated the email address. Please look at this one for review. Thanks.
Comment 6 Tim-Philipp Müller 2014-09-12 11:25:49 UTC
Please also put your full name into the patch next time, thanks!
Comment 7 Arun Raghavan 2014-09-29 14:57:31 UTC
Created attachment 287358 [details] [review]
pulsesink: Make emitting stream status messages synchronous

The stream status messages are emitted in the PA mainloop thread, which
means the mainloop lock is taken, followed by the Gst object lock (by
gst_element_post_message()). In all other locations, the order of
locking is reversed (this is unavoidable in a bunch of cases where the
object lock is taken by GstBaseSink or GstAudioBaseSink, and then we get
control to take the mainloop lock).

The only way to guarantee that the defer callback for stream status
messages doesn't deadlock is to either stop posting those messages, or
make sure that the message emission is completed before we proceed to
any point that might take the object lock before the mainloop lock
(which is what we do after this patch).
Comment 8 Arun Raghavan 2014-09-29 15:00:06 UTC
Reopening because the original fix was not complete. Attached patch should fix this properly.
Comment 9 Arun Raghavan 2014-09-30 00:58:26 UTC
Created attachment 287410 [details] [review]
pulsesink: Make emitting stream status messages synchronous

The stream status messages are emitted in the PA mainloop thread, which
means the mainloop lock is taken, followed by the Gst object lock (by
gst_element_post_message()). In all other locations, the order of
locking is reversed (this is unavoidable in a bunch of cases where the
object lock is taken by GstBaseSink or GstAudioBaseSink, and then we get
control to take the mainloop lock).

The only way to guarantee that the defer callback for stream status
messages doesn't deadlock is to either stop posting those messages, or
make sure that the message emission is completed before we proceed to
any point that might take the object lock before the mainloop lock
(which is what we do after this patch).
Comment 10 Arun Raghavan 2014-09-30 00:59:52 UTC
Comment on attachment 287410 [details] [review]
pulsesink: Make emitting stream status messages synchronous

Updated and pushed the patch with a few more comments about what was done.
Comment 11 Philippe Normand 2014-10-07 12:24:05 UTC
Hi, it seems like this patch introduced a regression, when a position query is done on the sink before it emits the stream-status message a deadlock happens:

Thread 6 (Thread 0x7f4e0ddb8700 (LWP 12951))

  • #0 __lll_lock_wait
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S line 135
  • #1 _L_lock_1081
    from /lib/x86_64-linux-gnu/libpthread.so.0
  • #2 __GI___pthread_mutex_lock
    at ../nptl/pthread_mutex_lock.c line 134
  • #3 g_mutex_lock
    at gthread-posix.c line 213
  • #4 gst_element_post_message_default
    at gstelement.c line 1677
  • #5 mainloop_enter_defer_cb
    at pulsesink.c line 1204
  • #6 ??
    from /usr/lib/x86_64-linux-gnu/libpulse.so.0
  • #7 pa_mainloop_dispatch
    from /usr/lib/x86_64-linux-gnu/libpulse.so.0
  • #8 pa_mainloop_iterate
    from /usr/lib/x86_64-linux-gnu/libpulse.so.0
  • #9 pa_mainloop_run
    from /usr/lib/x86_64-linux-gnu/libpulse.so.0
  • #10 ??
    from /usr/lib/x86_64-linux-gnu/libpulse.so.0
  • #11 ??
    from /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-5.0.so
  • #12 start_thread
    at pthread_create.c line 309
  • #13 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 111

Thread 1 (Thread 0x7f4e74279940 (LWP 12920))

  • #0 __lll_lock_wait
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S line 135
  • #1 _L_lock_1081
    from /lib/x86_64-linux-gnu/libpthread.so.0
  • #2 __GI___pthread_mutex_lock
    at ../nptl/pthread_mutex_lock.c line 134
  • #3 g_mutex_lock
    at gthread-posix.c line 213
  • #4 gst_base_sink_get_position
    at gstbasesink.c line 4399
  • #5 default_element_query
    at gstbasesink.c line 4671
  • #6 gst_audio_base_sink_query
    at gstaudiobasesink.c line 505
  • #7 WebCore::StreamMediaPlayerPrivateGStreamer::currentTime() const
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #8 WebCore::MediaPlayerPrivateInterface::currentTimeDouble() const
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #9 WebCore::MediaPlayer::currentTime() const
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #10 WebCore::HTMLMediaElement::refreshCachedTime() const
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #11 WebCore::HTMLMediaElement::currentMediaTime() const
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #12 WebCore::HTMLMediaElement::scheduleTimeupdateEvent(bool)
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #13 WebCore::HTMLMediaElement::playbackProgressTimerFired(WebCore::Timer<WebCore::HTMLMediaElement>&)
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #14 WebCore::ThreadTimers::sharedTimerFiredInternal()
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #15 WTF::GMainLoopSource::voidCallback()
    from /home/phil/wkbuild/lib/libjavascriptcoregtk-4.0.so.18
  • #16 WTF::GMainLoopSource::voidSourceCallback(WTF::GMainLoopSource*)
    from /home/phil/wkbuild/lib/libjavascriptcoregtk-4.0.so.18
  • #17 g_timeout_dispatch
    at gmain.c line 4450
  • #18 g_main_dispatch
    at gmain.c line 3065
  • #19 g_main_context_dispatch
    at gmain.c line 3641
  • #20 g_main_context_iterate
    at gmain.c line 3712
  • #21 g_main_loop_run
    at gmain.c line 3906
  • #22 WebProcessMainUnix
    from /home/phil/wkbuild/lib/libwebkit2gtk-4.0.so.37
  • #23 __libc_start_main
    at libc-start.c line 287
  • #24 _start

Comment 12 Arun Raghavan 2014-10-10 09:48:35 UTC
Okay, so it is not possible to emit this message within the PulseAudio thread context while maintaining locking order (GST_OBJECT_LOCK before pa_threaded_mainloop_lock).

This being the case, I see the following alternatives:

1. Create the message in the PA mainloop thread (since we need the thread id), but emit the enter/leave status messages from another thread (without the mainloop lock held)

2. Stop emitting the enter/leave status messages altogether

I'm leaning towards (1) unless someone sees a reason not to (the only thing I can think of is that there might be synchronous listeners of the stream status message that hope to be called in the audio mainloop thread context, but it's possible that this is not meaningful).
Comment 13 Tim-Philipp Müller 2014-10-10 10:09:53 UTC
The stream status messages are usually picked up with a sync handler to set thread priorities or somesuch, no?
Comment 14 Arun Raghavan 2014-10-10 10:18:03 UTC
That's the impression I got from the documentation. I can't imagine that PulseAudio is alone in using a lock to protect the loop thread vs. other threads, so this should be a more general problem?
Comment 15 Arun Raghavan 2014-10-22 13:57:03 UTC
We talked about this at GstConf and the conclusion was:

1. For now, I'm going to comment out the stream status messages

2. I'm going to try to add PA API to allow execution of a callback in the mainloop without the mainloop lock held

3. Once 2. is done, we can use that to reintroduce the stream status messages
Comment 16 Arun Raghavan 2014-10-22 17:42:39 UTC
The following fix has been pushed:
1631557 pulsesink: Temporarily disable stream status posting
Comment 17 Arun Raghavan 2014-10-22 17:42:47 UTC
Created attachment 289154 [details] [review]
pulsesink: Temporarily disable stream status posting

We need a mechanism in PulseAudio to allow running code outside the
mainloop lock. Then we'd be able to post to the bus (taking the
GST_OBJECT_LOCK), without worrying about locking order with the mainloop
lock, which is the current cause of deadlocks while trying to post the
stream status messages.