[Webkit-unassigned] [Bug 259504] [GStreamer][MSE] Web process deadlock when destroying ~MediaPlayerPrivateGStreamer

bugzilla-daemon at webkit.org bugzilla-daemon at webkit.org
Wed Jul 26 08:55:34 PDT 2023


https://bugs.webkit.org/show_bug.cgi?id=259504

--- Comment #4 from Alicia Boya García <aboya at igalia.com> ---
I see. I don't think that is the problem because:

Regarding:
> Seems like our MSE src element doesn't react to flush-start/stop events? 

I don't see any flush in the backtrace.

And regarding:
> Before pushing buffers to the pads we should check if we were asked to flush, like basesrc does...

WebKitMediaSrc checks this already.

    // Wait to receive an object from the queue (if we didn't get one already) or flush.
    streamingMembers->queueChangedOrFlushedCondition.wait(streamingMembers.mutex(), [&]() {
        return streamingMembers->isFlushing || object;
    });
    {
        // Ensure that notifyWhenNotEmpty()'s callback (if any) is cleared after this point.
        DataMutexLocker queue { stream->track->queueDataMutex() };
        queue->resetNotEmptyHandler();
    }
    if (streamingMembers->isFlushing) {
        gst_pad_pause_task(pad);
        return;
    }

What I see in the backtrace, rather than a flush, is a pad deactivation. On pad deactivations, WebKitMediaSrc unlocks the streaming thread, as expected.

        // Unblock the streaming thread.
        RefPtr<Stream>& stream = WEBKIT_MEDIA_SRC_PAD(pad)->priv->stream;
        {
            DataMutexLocker streamingMembers { stream->streamingMembersDataMutex };
            streamingMembers->isFlushing = true;
            streamingMembers->padLinkedOrFlushedCondition.notifyOne();
            streamingMembers->queueChangedOrFlushedCondition.notifyOne();
        }
        // Following gstbasesrc implementation, this code is not flushing downstream.
        // If there is any possibility of the streaming thread being blocked downstream the caller MUST flush before.
        // Otherwise a deadlock would occur as the next function tries to join the thread.
        gst_pad_stop_task(pad);
        {
            DataMutexLocker streamingMembers { stream->streamingMembersDataMutex };
            streamingMembers->isFlushing = false;
        }

But the traceback doesn't contain any calls to webKitMediaSrcActivateMode(), suggesting the process is getting stuck before it gets there.

Indeed, here we see the stuck thread trying to deactivate proxypad92 (linked to the ghostpad audio_0 of uridecodebin3):

Thread 5 (Thread 0x7fe2d383af40 (LWP 2)):
#0  futex_wait (private=0, expected=2, futex_word=0x7fe0f8013170) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex at entry=0x7fe0f8013170, private=0) at lowlevellock.c:49
#2  0x00007fe2db6a5477 in lll_mutex_lock_optimized (mutex=0x7fe0f8013170) at pthread_mutex_lock.c:48
#3  ___pthread_mutex_lock (mutex=0x7fe0f8013170) at pthread_mutex_lock.c:128
#4  0x00007fe2d751634d in g_rec_mutex_lock (mutex=mutex at entry=0x7fe0f801d470) at ../glib/gthread-posix.c:397
#5  0x00007fe2d80bee4a in post_activate (new_mode=<optimized out>, pad=<optimized out>) at ../gst/gstpad.c:1050
#6  activate_mode_internal (pad=pad at entry=0x7fe0f801d400 [GstProxyPad|proxypad92], parent=parent at entry=0x7fe0f801d190 [GstGhostPad|audio_0], mode=mode at entry=GST_PAD_MODE_PUSH, active=active at entry=0) at ../gst/gstpad.c:1228
#7  0x00007fe2d80bfc87 in gst_pad_activate_mode (pad=0x7fe0f801d400 [GstProxyPad|proxypad92], mode=GST_PAD_MODE_PUSH, active=0) at ../gst/gstpad.c:1326
#8  0x00007fe2d80aca39 in gst_ghost_pad_activate_push_default (pad=<optimized out>, parent=<optimized out>, active=0) at ../gst/gstghostpad.c:371
#9  0x00007fe2d80bee07 in activate_mode_internal (pad=pad at entry=0x7fe0f801d190 [GstGhostPad|audio_0], parent=parent at entry=0x560e4f7bea30 [GstURIDecodeBin3|uridecodebin3], mode=mode at entry=GST_PAD_MODE_PUSH, active=active at entry=0) at ../gst/gstpad.c:1221
#10 0x00007fe2d80bf93b in gst_pad_set_active (pad=0x7fe0f801d190 [GstGhostPad|audio_0], active=0) at ../gst/gstpad.c:1119
#11 0x00007fe2d8078f9b in activate_pads (vpad=<optimized out>, ret=0x7ffcb91ec2c0, active=0x7ffcb91ec2bc) at ../gst/gstbin.c:2630
#12 0x00007fe2d80b0b15 in gst_iterator_fold (it=0x560e4f769db0, func=0x7fe2d8078f70 <activate_pads>, ret=0x7ffcb91ec2c0, user_data=0x7ffcb91ec2bc) at ../gst/gstiterator.c:617
#13 0x00007fe2d80790b0 in iterator_activate_fold_with_resync (user_data=0x7ffcb91ec2bc, iter=0x560e4f769db0) at ../gst/gstbin.c:2653
#14 gst_bin_src_pads_activate (bin=bin at entry=0x560e4f7bea30 [GstURIDecodeBin3|uridecodebin3], active=<optimized out>, active at entry=0) at ../gst/gstbin.c:2687

That recursive mutex that is being waited for in post_activate is the stream lock of proxypad92.

Now, who is holding proxypad92's stream lock?

Thread 36 (Thread 0x7fe0edffb6c0 (LWP 196)):
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x00007fe2d7516f6d in g_cond_wait (cond=cond at entry=0x560e4f5ebd18, mutex=mutex at entry=0x560e4f5ebca8) at ../glib/gthread-posix.c:1475
#2  0x00007fe2d80bd3fd in do_probe_callbacks (pad=0x560e4f5ebc90 [GstProxyPad|proxypad82], info=<optimized out>, defaultval=<optimized out>) at ../gst/gstpad.c:3899
#3  0x00007fe2d80cc66a in gst_pad_push_event_unchecked (pad=0x560e4f5ebc90 [GstProxyPad|proxypad82], event=0x7fe0b000e600 [GstEvent], type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5521
#4  0x00007fe2d80c6f68 in push_sticky (pad=pad at entry=0x560e4f5ebc90 [GstProxyPad|proxypad82], ev=ev at entry=0x7fe0edff98d0, user_data=user_data at entry=0x7fe0edff9940) at ../gst/gstpad.c:4057
#5  0x00007fe2d80bc2b5 in events_foreach (pad=0x560e4f5ebc90 [GstProxyPad|proxypad82], func=0x7fe2d80c6ec0 <push_sticky>, user_data=0x7fe0edff9940) at ../gst/gstpad.c:613
#6  0x00007fe2d80cce11 in check_sticky (event=0x7fe0b000e600 [GstEvent], pad=0x560e4f5ebc90 [GstProxyPad|proxypad82]) at ../gst/gstpad.c:4116
#7  gst_pad_push_event (pad=0x560e4f5ebc90 [GstProxyPad|proxypad82], event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:5705
#8  0x00007fe2d80c6ea3 in event_forward_func (pad=pad at entry=0x560e4f5ebc90 [GstProxyPad|proxypad82], data=data at entry=0x7fe0edff9a60) at ../gst/gstpad.c:3130
#9  0x00007fe2d80c6c1e in gst_pad_forward (pad=pad at entry=0x560e4f5eb8b0 [GstGhostPad|audio_sink], forward=forward at entry=0x7fe2d80c6de0 <event_forward_func>, user_data=user_data at entry=0x7fe0edff9a60) at ../gst/gstpad.c:3084
#10 0x00007fe2d80c6d09 in gst_pad_event_default (pad=0x560e4f5eb8b0 [GstGhostPad|audio_sink], parent=<optimized out>, event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:3181
#11 0x00007fe2d80cbabd in gst_pad_send_event_unchecked (pad=pad at entry=0x560e4f5eb8b0 [GstGhostPad|audio_sink], event=event at entry=0x7fe0b000e600 [GstEvent], type=<optimized out>, type at entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5939
#12 0x00007fe2d80cc1a7 in gst_pad_push_event_unchecked (pad=0x7fe0f801d190 [GstGhostPad|audio_0], event=0x7fe0b000e600 [GstEvent], type=<optimized out>) at ../gst/gstpad.c:5572
#13 0x00007fe2d80c6f68 in push_sticky (pad=pad at entry=0x7fe0f801d190 [GstGhostPad|audio_0], ev=ev at entry=0x7fe0edff9cc0, user_data=user_data at entry=0x7fe0edff9d30) at ../gst/gstpad.c:4057
#14 0x00007fe2d80bc2b5 in events_foreach (pad=0x7fe0f801d190 [GstGhostPad|audio_0], func=0x7fe2d80c6ec0 <push_sticky>, user_data=0x7fe0edff9d30) at ../gst/gstpad.c:613
#15 0x00007fe2d80cce11 in check_sticky (event=0x7fe0b000e600 [GstEvent], pad=0x7fe0f801d190 [GstGhostPad|audio_0]) at ../gst/gstpad.c:4116
#16 gst_pad_push_event (pad=0x7fe0f801d190 [GstGhostPad|audio_0], event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:5705
#17 0x00007fe2d80c6ea3 in event_forward_func (pad=pad at entry=0x7fe0f801d190 [GstGhostPad|audio_0], data=data at entry=0x7fe0edff9e50) at ../gst/gstpad.c:3130
#18 0x00007fe2d80c6c1e in gst_pad_forward (pad=pad at entry=0x7fe0f801d400 [GstProxyPad|proxypad92], forward=forward at entry=0x7fe2d80c6de0 <event_forward_func>, user_data=user_data at entry=0x7fe0edff9e50) at ../gst/gstpad.c:3084
#19 0x00007fe2d80c6d09 in gst_pad_event_default (pad=0x7fe0f801d400 [GstProxyPad|proxypad92], parent=<optimized out>, event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:3181
#20 0x00007fe2d80cbabd in gst_pad_send_event_unchecked (pad=pad at entry=0x7fe0f801d400 [GstProxyPad|proxypad92], event=event at entry=0x7fe0b000e600 [GstEvent], type=<optimized out>, type at entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5939
#21 0x00007fe2d80cc1a7 in gst_pad_push_event_unchecked (pad=0x7fe0f8012660 [GstGhostPad|audio_0], event=0x7fe0b000e600 [GstEvent], type=<optimized out>) at ../gst/gstpad.c:5572
#22 0x00007fe2d80c6f68 in push_sticky (pad=pad at entry=0x7fe0f8012660 [GstGhostPad|audio_0], ev=ev at entry=0x7fe0edffa0b0, user_data=user_data at entry=0x7fe0edffa120) at ../gst/gstpad.c:4057
#23 0x00007fe2d80bc2b5 in events_foreach (pad=0x7fe0f8012660 [GstGhostPad|audio_0], func=0x7fe2d80c6ec0 <push_sticky>, user_data=0x7fe0edffa120) at ../gst/gstpad.c:613
#24 0x00007fe2d80cce11 in check_sticky (event=0x7fe0b000e600 [GstEvent], pad=0x7fe0f8012660 [GstGhostPad|audio_0]) at ../gst/gstpad.c:4116
#25 gst_pad_push_event (pad=0x7fe0f8012660 [GstGhostPad|audio_0], event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:5705
#26 0x00007fe2d80c6ea3 in event_forward_func (pad=pad at entry=0x7fe0f8012660 [GstGhostPad|audio_0], data=data at entry=0x7fe0edffa240) at ../gst/gstpad.c:3130
#27 0x00007fe2d80c6c1e in gst_pad_forward (pad=pad at entry=0x7fe0f8009a90 [GstProxyPad|proxypad91], forward=forward at entry=0x7fe2d80c6de0 <event_forward_func>, user_data=user_data at entry=0x7fe0edffa240) at ../gst/gstpad.c:3084
#28 0x00007fe2d80c6d09 in gst_pad_event_default (pad=0x7fe0f8009a90 [GstProxyPad|proxypad91], parent=<optimized out>, event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:3181
#29 0x00007fe2d80cbabd in gst_pad_send_event_unchecked (pad=pad at entry=0x7fe0f8009a90 [GstProxyPad|proxypad91], event=event at entry=0x7fe0b000e600 [GstEvent], type=<optimized out>, type at entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5939
#30 0x00007fe2d80cc1a7 in gst_pad_push_event_unchecked (pad=0x7fe0f8005180 [GstPad|src], event=0x7fe0b000e600 [GstEvent], type=<optimized out>) at ../gst/gstpad.c:5572
#31 0x00007fe2d80c6f68 in push_sticky (pad=pad at entry=0x7fe0f8005180 [GstPad|src], ev=ev at entry=0x7fe0edffa4a0, user_data=user_data at entry=0x7fe0edffa510) at ../gst/gstpad.c:4057
#32 0x00007fe2d80bc2b5 in events_foreach (pad=0x7fe0f8005180 [GstPad|src], func=0x7fe2d80c6ec0 <push_sticky>, user_data=0x7fe0edffa510) at ../gst/gstpad.c:613
#33 0x00007fe2d80cce11 in check_sticky (event=0x7fe0b000e600 [GstEvent], pad=0x7fe0f8005180 [GstPad|src]) at ../gst/gstpad.c:4116
#34 gst_pad_push_event (pad=0x7fe0f8005180 [GstPad|src], event=0x7fe0b000e600 [GstEvent]) at ../gst/gstpad.c:5705
#35 0x00007fe2d80cbabd in gst_pad_send_event_unchecked (pad=pad at entry=0x7fe0f80021a0 [GstPad|sink], event=event at entry=0x7fe0b000e600 [GstEvent], type=<optimized out>, type at entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5939
#36 0x00007fe2d80cc1a7 in gst_pad_push_event_unchecked (pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0], event=0x7fe0b000e600 [GstEvent], type=<optimized out>) at ../gst/gstpad.c:5572
#37 0x00007fe2d80c6f68 in push_sticky (pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0], ev=0x7fe0edffa780, user_data=0x7fe0edffa800) at ../gst/gstpad.c:4057
#38 0x00007fe2d80bc2b5 in events_foreach (pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0], func=0x7fe2d80cac80 <sticky_changed>, user_data=0x7fe0edffa800) at ../gst/gstpad.c:613
#39 0x00007fe2d80cc5f9 in gst_pad_push_event_unchecked (pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0], event=0x7fe0b000ff40 [GstEvent], type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at ../gst/gstpad.c:5548
#40 0x00007fe2d80c6f68 in push_sticky (pad=pad at entry=0x7fe0b00116e0 [GstMultiQueuePad|src_0], ev=ev at entry=0x7fe0edffa920, user_data=user_data at entry=0x7fe0edffa990) at ../gst/gstpad.c:4057
#41 0x00007fe2d80bc2b5 in events_foreach (pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0], func=0x7fe2d80c6ec0 <push_sticky>, user_data=0x7fe0edffa990) at ../gst/gstpad.c:613
#42 0x00007fe2d80cce11 in check_sticky (event=0x7fe0b000ff40 [GstEvent], pad=0x7fe0b00116e0 [GstMultiQueuePad|src_0]) at ../gst/gstpad.c:4116
#43 gst_pad_push_event (pad=pad at entry=0x7fe0b00116e0 [GstMultiQueuePad|src_0], event=event at entry=0x7fe0b000ff40 [GstEvent]) at ../gst/gstpad.c:5705
#44 0x00007fe24ff54aa3 in gst_single_queue_push_one (allow_drop=<synthetic pointer>, object=0x7fe0b000ff40 [GstEvent], sq=0x7fe0b0010b10, mq=<optimized out>) at ../plugins/elements/gstmultiqueue.c:2079
#45 gst_multi_queue_loop (pad=<optimized out>) at ../plugins/elements/gstmultiqueue.c:2358
#46 0x00007fe2d80fd134 in gst_task_func (task=0x7fe0b0011ae0 [GstTask|multiqueue5:src_0]) at ../gst/gsttask.c:384
#47 0x00007fe2d74e8582 in g_thread_pool_thread_proxy (data=<optimized out>) at ../glib/gthreadpool.c:350
#48 0x00007fe2d74e7b59 in g_thread_proxy (data=0x7fe2c40019d0) at ../glib/gthread.c:831
#49 0x00007fe2db6a1e09 in start_thread (arg=<optimized out>) at pthread_create.c:444
#50 0x00007fe2db728d74 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

In that trace we can see that a pad downstream of proxypad92, proxypad82 is waiting for a blocking probe to be removed. proxypad82 is connected to audio_sink, presumably from playsink -- wish the gdb script printed the elements parenting the pads. playsink does in fact use blocking probes, which are added and removed with its audio_set_blocked/video_set_blocked functions. I know for a fact that playsink has race conditions in the handling of flushes, because I'm working on fixing them. The same kind of issues also exist in decodebin3 and presumably more of the playbin3 ecosystem. I wouldn't be surprised at all if the pad deactivation is also racy.

Notably, notice:
Thread 5 (Thread 0x7fe2d383af40 (LWP 2)):
[...]
#19 0x00007fe2d807adb8 in gst_bin_element_set_state (next=<optimized out>, current=<optimized out>, start_time=0 [0:00:00.000000000], base_time=0 [0:00:00.000000000], element=0x560e4f7bea30 [GstURIDecodeBin3|uridecodebin3], bin=<optimized out>) at ../gst/gstbin.c:2582
#20 gst_bin_change_state_func (element=0x560e4f7bde10 [GstPlayBin3|MSE-ndp_video_player_1690325110275-5], transition=GST_STATE_CHANGE_PAUSED_TO_READY) at ../gst/gstbin.c:2931

gst_bin_change_state_func is meant to iterate changing state from downstream to upstream. There we see it changing the state to uridecodebin3, but has it actually changed the state for playsink first? Knowing that blocking probes get removed on pad deactivation (see pre_activate() in gstpad.c, case GST_PAD_MODE_NONE), I suspect it has not.

-- 
You are receiving this mail because:
You are the assignee for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.webkit.org/pipermail/webkit-unassigned/attachments/20230726/f3b0830a/attachment-0001.htm>


More information about the webkit-unassigned mailing list