[GStreamer] MediaPlayerPrivateGStreamer: Abort stale tasks on flushes

[ntrrgc]

e55d190

[GStreamer] MediaPlayerPrivateGStreamer: Abort stale tasks on flushes
https://bugs.webkit.org/show_bug.cgi?id=244534

Reviewed by Philippe Normand.

This patch is a combination of a follow-up of
#3746, and a fix for a race
condition I independently discovered before said PR was published.

Minor cleanups for pr/3746 are done, additional logging is added,
MediaPlayerPrivateGStreamer::m_abortableTaskQueue is renamed to
MediaPlayerPrivateGStreamer::m_sinkTaskQueue, comments are added, and
most importantly: the task queue is flushed when a GStreamer flush is
received. This fixes a race condition on MSE flushes.

To compensate the additional logic added to the WebKit video sink probe,
this patch refactors the function, getting rid of the early return
spaghetti it had slowly become over the years.

In the process, I found the code for calling flushCurrentBuffer() on
FLUSH_START in the previous code was actually unreachable and had been
so for the most part of a year, as an accident of an early return in the
old code (FLUSH_START events have the
GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM flag. The old code did an early
return when that flag was found for an event other than a tag event).

Figuring out all bugs with flushCurrentBuffer() and what usages it
should have is very much outside of the scope of this patch. Instead,
this patch makes no change on behavior and adds a FIXME section
explaining the situation and how it needs further work.

* Source/WebCore/platform/graphics/gstreamer/GStreamerVideoSinkCommon.cpp:
(webKitVideoSinkSetMediaPlayerPrivate):
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:
(WebCore::MediaPlayerPrivateGStreamer::~MediaPlayerPrivateGStreamer):
(WebCore::MediaPlayerPrivateGStreamer::updateVideoOrientation):
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h:
(WebCore::MediaPlayerPrivateGStreamer::sinkTaskQueue):

Canonical link: https://commits.webkit.org/254142@main

539d948

Misc	iOS, tvOS & watchOS	macOS	Linux	Windows
✅ 🧪 style	✅ 🛠 ios	✅ 🛠 mac	✅ 🛠 wpe	✅ 🛠 🧪 win
✅ 🧪 bindings	✅ 🛠 ios-sim	✅ 🛠 mac-debug	✅ 🛠 gtk	✅ 🛠 wincairo
✅ 🧪 webkitperl	✅ 🧪 ios-wk2	✅ 🛠 mac-AS-debug	✅ 🧪 gtk-wk2
	✅ 🧪 api-ios	✅ 🧪 api-mac	🧪 api-gtk
	✅ 🛠 tv	✅ 🧪 mac-wk1
	✅ 🛠 tv-sim	✅ 🧪 mac-wk2
✅ 🛠 🧪 merge	✅ 🛠 watch	✅ 🧪 mac-AS-debug-wk2
	✅ 🛠 watch-sim	✅ 🧪 mac-wk2-stress

[webkit-early-warning-system]

EWS run on previous version of this PR (hash dbb1766)

Misc	iOS, tvOS & watchOS	macOS	Linux	Windows
✅ 🧪 style	✅ 🛠 ios	✅ 🛠 mac	✅ 🛠 wpe	✅ 🛠 🧪 win
✅ 🧪 bindings	✅ 🛠 ios-sim	✅ 🛠 mac-debug	✅ 🛠 gtk	✅ 🛠 wincairo
✅ 🧪 webkitperl	✅ 🧪 ios-wk2	✅ 🛠 mac-AS-debug	❌ 🧪 gtk-wk2
	✅ 🧪 api-ios	✅ 🧪 api-mac	✅ 🧪 api-gtk
	✅ 🛠 tv	✅ 🧪 mac-wk1
	✅ 🛠 tv-sim	✅ 🧪 mac-wk2
🛠 🧪 merge	✅ 🛠 watch	✅ 🧪 mac-AS-debug-wk2
	✅ 🛠 watch-sim	✅ 🧪 mac-wk2-stress

[philn]

Is this retry label supposed to trigger something already?

[ntrrgc]

Is this retry label supposed to trigger something already?

I hoped so, but didn't seem so. I just re-uploaded a version with indentation fixes.

[webkit-early-warning-system]

EWS run on previous version of this PR (hash 4348a5a)

Misc	iOS, tvOS & watchOS	macOS	Linux	Windows
✅ 🧪 style	✅ 🛠 ios	✅ 🛠 mac	✅ 🛠 wpe	✅ 🛠 🧪 win
✅ 🧪 bindings	✅ 🛠 ios-sim	✅ 🛠 mac-debug	✅ 🛠 gtk	✅ 🛠 wincairo
✅ 🧪 webkitperl	✅ 🧪 ios-wk2	✅ 🛠 mac-AS-debug	❌ 🧪 gtk-wk2
	✅ 🧪 api-ios	✅ 🧪 api-mac	✅ 🧪 api-gtk
	✅ 🛠 tv	✅ 🧪 mac-wk1
	✅ 🛠 tv-sim	✅ 🧪 mac-wk2
	✅ 🛠 watch	✅ 🧪 mac-AS-debug-wk2
	✅ 🛠 watch-sim	✅ 🧪 mac-wk2-stress

[ntrrgc]

Interesting, compositing/video/video-border-radius-clipping.html failed both times. It may not be a fluke then... Will investigate.

[ntrrgc]

Okay, this has been a ride...

First, I have learned that video output doesn't work in our test runner.

0:00:03.530073170    56       0x7f6ac0 WARN       webkitmediaplayer PlatformDisplayGStreamer.cpp:115:tryEnsureGstGLContext: Failed to fill in GStreamer context: could not retrieve fbconfig from its ID 0x42. Wrong Display or Screen?

That would be its own issue to solve. Still, somehow, the tester managed to catch an actual issue, even if kind of by accident: With the new code, at the end of playback the frame disappears, instead of remaining green as it should, and as it did with the old code. That is a undoubtedly a regression.

I pinpointed the problem to the video sink probe, confirming leaving the old code doesn't expose the bug. Then I analyzed both by hand. The only difference should be that the new one also calls AbortableTaskQueue methods. But removing such calls didn't return the old behavior, so I must have been missing something in my analysis.

I added logging to both versions, processed logs, and eventually found this:

With the new code:

got flush-start event: 0x2368200, time 99:99:99.999999999, seq-num 339, (NULL)
flushCurrentBuffer
return

With the old code:

got flush-start event: 0x1d38200, time 99:99:99.999999999, seq-num 339, (NULL)
return1

Shockers! The old code doesn't do anything in reaction to flushes. Which is a bit strange since there is clearly code to call flushCurrentBuffer, a comment saying doing that is necessary and of course the probe itself has GST_PAD_PROBE_TYPE_EVENT_FLUSH among the accepted types. So how come?

This is the return that prevents that code from being reachable:

if (info->type & GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) {
    if (GST_EVENT_TYPE(GST_PAD_PROBE_INFO_EVENT(info)) != GST_EVENT_TAG)
        return GST_PAD_PROBE_OK;

TIL When a flush event is send to a probe, info->type has both GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM and GST_PAD_PROBE_TYPE_EVENT_FLUSH set. This is despite the explicit need to filter by GST_PAD_PROBE_TYPE_EVENT_FLUSH if you want to process flush events. It's not symmetrical.

Doing a bit of code archeology, I found that code to come from 05df690#diff-f6cc7b9fa85e4704ddb4a5f5e1f3300b29ee850f68259ddae19867015833836bR261-R263 Therefore the "flushCurrentBuffer() on FLUSH_START" code has been unreachable since https://commits.webkit.org/245491@main (22 Dec 2021).

That change was committed because a previous commit (18 Oct 2021) to add processing of tag events had the unintended consequence of calling flushCurrentBuffer() on every event. It took me a while to see how!

I hope we can agree that the stubborness of using early returns in the probe algorithm has turned it into spaghetti code, only worsening every time anyone wanted to add a feature. It took me quite a while to understand what the algorithm was supposed to do, both when making this PR, later when analyzing this bug, and in the end my analysis was still wrong! When I added logs, there was a total of 6 exit paths!

So, where does this flushCurrentBuffer() come from? From this old commit from 13 Jun 2017 This is the commit that introduced the whole probe, which back then was pretty simple:

GRefPtr<GstPad> pad = adoptGRef(gst_element_get_static_pad(appsink, "sink"));
gst_pad_add_probe (pad.get(), GST_PAD_PROBE_TYPE_EVENT_FLUSH, [] (GstPad*, GstPadProbeInfo* info,  gpointer userData) -> GstPadProbeReturn {
    if (GST_EVENT_TYPE (GST_PAD_PROBE_INFO_EVENT (info)) != GST_EVENT_FLUSH_START)
        return GST_PAD_PROBE_OK;

    auto* player = static_cast<MediaPlayerPrivateGStreamerBase*>(userData);
    player->flushCurrentBuffer();
    return GST_PAD_PROBE_OK;
}, this, nullptr);

The commit message stated:

However, it is not enough to release the GstMemory. The platform layer proxy should copy current buffer to show it to the compositor instead of a blank frame. It prevents flickerings until getting a new frame after handling flush events.

And for this purpose it added a new function, TextureMapperPlatformLayerProxy::dropCurrentBufferWhilePreservingTexture(). I have no experience with TextureMapperPlatformLayerProxy or much of the graphics stack, and I don't understand how that code that just adds asynchronous operations would ensure that the GstMemory is released by the time a new buffer comes to the decoder, if it does at all. Also, it's clear as of now, and probably for a long time, it doesn't succeed in preventing flickering, as calling flushCurrentBuffer() has the visible side effect of consistently making the flushed frame invisible to the user.

An older version of said code existed earlier before in the WPEWebKit fork, being originally committed in 10 Jun 2016. That version explicitly introduced flicker, its commit message reading:

This patch removes current GstSample when player got the flush start event. it destructs the platform layer buffer any time there is a flush start event.

This removes the current video frame from the screen when it starts to seek. It is not a desired behavior from UX point of view.

We need to evoluate whether is it okay not to free the GstBuffer when there is a flush event.

This is the same flicker the later upstream commit would supposedly avoid with dropCurrentBufferWhilePreservingTexture().

Still, this is only flush events. Why are we doing anything on DRAIN queries? That comes from this WPEWebKit commit from 23 Jan 2015 Back then it was a different function:

void MediaPlayerPrivateGStreamerBase::triggerDrain()
{
    GMutexLocker<GMutex> lock(m_sampleMutex);
    m_videoSize.setWidth(0);
    m_videoSize.setHeight(0);
    if (m_sample)
        gst_sample_unref(m_sample);
    m_sample = 0;
}

Still, neither commit provides any explanation on why we need to call flushCurrentBuffer() on FLUSH_START events or DRAIN queries. There is currently code with a vague explanation, which I added as part of 4fd8d9a, but that comes from asking @eocanha.

// In some platforms (e.g. OpenMAX on the Raspberry Pi) when a resolution change occurs the
// pipeline has to be drained before a frame with the new resolution can be decoded.
// In this context, it's important that we don't hold references to any previous frame
// (e.g. m_sample) so that decoding can continue.
// We are also not supposed to keep the original frame after a flush.

So now I'm left wondering:

1. Why do we have this piece of code? What purpose does it serve?
2. Why on FLUSH_START events and on DRAIN queries? Why not only on DRAIN queries? Why not only in FLUSH_START events?
3. What is a DRAIN query supposed to do in a video sink element? I can't find an explanation for this in GStreamer code or documentation.
4. The code to call flushCurrentBuffer() on flush events has been dead code for the most part of this year. Is this a problem?
5. flushCurrentBuffer() has had the side effect of making the last frame of the video player invisible for a very long time. Whatever code was originally written to prevent that in 2017 is clearly not working today. How can we fix that?

[eocanha]

Some explanations about why the m_sample buffer must be freed on flushes:

The Raspberry Pi OMX decoder (among others) decodes video onto buffers using a special (and very scarce) GPU memory. It must be GPU memory because that's the only way to achieve zero-copy on those platforms. That's because that GPU memory can (in some way that I don't exactly know) be converted/used as a GL texture for the GPU (hence zero-copy).
Those GstBuffers with decoded data aren't normal GstBuffers. They come from a buffer pool (a set of allocated buffers) which has only 3 or 4 available buffers (that memory was scarce, remember?). If buffers aren't returned to the pool (eg: because of a memory leak or whatever, or because keeping one of them here as m_sample) the whole decoding pipeline stalls when the buffer pool doesn't have any more buffers to provide to the decoder when it asks for a new one.

Some context about a drain operation in GStreamer:

https://gstreamer.freedesktop.org/documentation/additional/design/sparsestreams.html?gi-language=c#still-framemenu-support
that text talks about "drain events", but I don't think those events actually exist (or actually exist anymore). In my understanding, they are now referred as drain queries. A drain query is like a flush event (in the sense that its purpose is to "empty" the element), but its goal (I think) is to force the element to get all its buffers out downstream.

[webkit-early-warning-system]

EWS run on previous version of this PR (hash 630eb70)

Misc	iOS, tvOS & watchOS	macOS	Linux	Windows
❌ 🧪 style	✅ 🛠 ios	✅ 🛠 mac	✅ 🛠 wpe	✅ 🛠 🧪 win
✅ 🧪 bindings	✅ 🛠 ios-sim	✅ 🛠 mac-debug	✅ 🛠 gtk	✅ 🛠 wincairo
✅ 🧪 webkitperl	✅ 🧪 ios-wk2	✅ 🛠 mac-AS-debug	✅ 🧪 gtk-wk2
	🧪 api-ios	🧪 api-mac	🧪 api-gtk
	✅ 🛠 tv	🧪 mac-wk1
	✅ 🛠 tv-sim	✅ 🧪 mac-wk2
	✅ 🛠 watch	🧪 mac-AS-debug-wk2
	✅ 🛠 watch-sim	✅ 🧪 mac-wk2-stress

[webkit-early-warning-system]

539d948

Misc	iOS, tvOS & watchOS	macOS	Linux	Windows
✅ 🧪 style	✅ 🛠 ios	✅ 🛠 mac	✅ 🛠 wpe	✅ 🛠 🧪 win
✅ 🧪 bindings	✅ 🛠 ios-sim	✅ 🛠 mac-debug	✅ 🛠 gtk	✅ 🛠 wincairo
✅ 🧪 webkitperl	✅ 🧪 ios-wk2	✅ 🛠 mac-AS-debug	✅ 🧪 gtk-wk2
	✅ 🧪 api-ios	✅ 🧪 api-mac	🧪 api-gtk
	✅ 🛠 tv	✅ 🧪 mac-wk1
	✅ 🛠 tv-sim	✅ 🧪 mac-wk2
✅ 🛠 🧪 merge	✅ 🛠 watch	✅ 🧪 mac-AS-debug-wk2
	✅ 🛠 watch-sim	✅ 🧪 mac-wk2-stress

[webkit-commit-queue]

Committed 254142@main (e55d190): https://commits.webkit.org/254142@main

Reviewed commits have been landed. Closing PR #3802 and removing active labels.