Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WPE 2.38 - Video not smooth during initial few seconds for progressive video playback #1309

Open
pradeep-raveendranpillai-infosys opened this issue Apr 11, 2024 · 59 comments
Assignees
Labels

Comments

@pradeep-raveendranpillai-infosys
Copy link

pradeep-raveendranpillai-infosys commented Apr 11, 2024

On video accelerator devices using wpe 2.38, when progressive video content (e.g. CNN ) is played, it is seen that the video is not smooth (frequent freezes are seen) for the initial few seconds after which video plays smoothly. This issue is not seen with WPE 2.22 version though.

The below workaround is currently undertaken to fix the issue. But it has side effect like video plays in slow speed when the network bandwidth is limited.

--- a/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp
+++ b/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp
@@ -2132,7 +2132,7 @@ void MediaPlayerPrivateGStreamer::updateBufferingStatus(GstBufferingMode mode, d
m_fillTimer.stop();

+// Force buffering flag to be always false so we don't enter buffering state at all
+m_isBuffering = false;
m_bufferingPercentage = percentage;
switch (mode) {

Sample video is attached.
https://github.com/WebPlatformForEmbedded/WPEWebKit/assets/156415435/373b930e-a06a-44d1-a04b-d83cf52c8360

@eocanha
Copy link
Member

eocanha commented Apr 16, 2024

It's true that buffering in Broadcom devices based on Nexus has been problematic in the past in previous WPE versions, due to the nature of Nexus and how it "sucks" as much data as possible, interfering with the buffering levels measured by WebKit. However, the proposed change is effectively disabling any kind of initial buffering and that doesn't look like a good idea.

I've just tested the change you proposed in WebKit upstream and it breaks these layout tests on my local setup:

http/tests/media/video-play-stall-seek.html
http/tests/media/video-play-waiting.html
media/destructor-logging-crash.html
media/modern-media-controls/button/button-on.html
media/request-video-frame-seek.html

Can you provide a link to the specific video that is causing the problems in your case, as well as a pipeline dump, so I can try to reproduce a similar setup here and analyze how buffering behaves?

In order to get pipeline dumps, you need to define export GST_DEBUG_DUMP_DOT_DIR=/tmp and then get the .dot files generated on /tmp.

@eocanha
Copy link
Member

eocanha commented Apr 18, 2024

I haven't been to reproduce the reported behaviour consistently with my (fast) internet connection on a Nexus set-top-box. Still, I've created an experimental eocanha/eocanha-debug-148 branch with some commits adapted from #792, where a similar problem was reported. The relevant commits there are the most recent three ones.

What that branch does is to have into account the bytes buffered by Nexus' PlayPump, as well as the ones buffered by a multiqueue attached before brcmvidfilter (if any, it wasn't present in the pipelines I got for your test video) and recompute the buffering percentage in a more realistic way.

I got full buffering in 10 sec using a network connection capped to 8000 Mbps (the bandwidth of the test video, 8 Mbit per second = 1 Mbyte per second --> 10 sec to fill the GstQueue2 buffer of 10MB). When the network bandwidth was doubled to 16 Mbps, buffering took 5 sec and I could appreciate more clearly the corrections done by the commits.

If this commits solve your problem, or at least improve them up to a tolerable level, I can work on trying to upstream it.

@pradeep-raveendranpillai-infosys
Copy link
Author

Thanks, Enrique.

I tried the last three recent commits from your branch, but it doesn't seem to make any improvement in the behavior. I have attached logs for two video playbacks when the issue happens.
log1.txt
log2.txt

You can please try reproducing the issue using any of the below CNN url. Please try to play as much videos.
https://widgets.metrological.com/lightning/liberty/2e3c4fc22f0d35e3eb7fdb47eb7d4658#app:com.metrological.app.CNN
https://widgets.metrological.com/lightning/rdk/d431ce8577be56e82630650bf701c57d#app:com.metrological.app.CNN

I tried playing same videos on my PC simultaneously to compare the behavior. On PC the issue never happens, while on my STB I can see minimum one pausing occurring after video starts to play.

@eocanha
Copy link
Member

eocanha commented Apr 19, 2024

UPDATE: This request below may not be relevant anymore, since the problem isn't related to how fast the buffering percentage evolves, but related to buffering being considered as complete regardless of the percentage. See the next comment.

I'm going to try, but if you could provide some info about your network bandwidth, or if we could try to simulate the same bandwidth in your environment and in mine, things would be more reproducible.

I'm using Kubuntu 22.04 LTS Jammy Jellyfish as my development environment (but ignore the "K", it's like a regular Ubuntu under the hood) and I'm sharing my internet connection with the set-top-box, so I can run this bandwidth-limit.txt
bandwidth shaper script on the second ethernet port that gives access to the STB.

If it's possible for you, run that script on your side and tell me with which bandwidth I should work.

@eocanha
Copy link
Member

eocanha commented Apr 19, 2024

Ok... I see what the problem is in your case (but I still don't know how to solve it, I just know where to look at). The problem is that the pipeline in log1.txt is moving to PLAYING state before the buffering reaches 100%, and that's why underruns happen and the video you posted in the Issue description stutters at the beginning. I'm assuming that video was recorded without your patch, right?

The difference with what I can reproduce here is that in my case the "[Buffering] Complete." log line inly happens after the buffering has reached 100%, while in your case it already happens at the begining, even before the percentage is still at 5% (corrected to 16% with playpump).

I'm attaching my (filtered) log for comparison: filtered-log.txt

The webpage I use is a simple one that creates a <video> and loads it with the raw cms3-CNN-amanpour-brian-greene-primary-356881-1501804-1920x1080_8000k.mp4 video src you provided.

I still have to check what happens with the CNN app you provided today.

@pradeep-raveendranpillai-infosys
Copy link
Author

Yes, the video was recorded without my patch (With patch the issue is not there). Even without limiting the network bandwidth I am able to reproduce the issue. My test environment network bandwidth is also very good (> 600 Mbps). But you can try reducing the video bandwidth to 8Mbps - 12 Mbps and see if it helps.

@eocanha
Copy link
Member

eocanha commented Apr 23, 2024

I haven't been able to reproduce the behaviour shown in your logs (and therefore the bug) here, so we'll have to debug this "by email" :-/

Could you please apply the latest 9f5ca3d commit in the eocanha/eocanha-debug-148 branch to your environment and send me new logs? That commits adds some extra logs to try to debug the causes that make m_isBuffering to change. With that information, I can hopefully understand why my environment waits for 100% buffering to start, while yours starts ahead of time, with not enough data buffered, causing the stuttering.

@pradeep-raveendranpillai-infosys
Copy link
Author

Please find the logs for two of the videos where the issue was reproduced.
log1.24apr.txt
log2.24apr.txt

@eocanha
Copy link
Member

eocanha commented Apr 24, 2024

I've analyzed your new logs provided by email and I've found that the query block is being run in your case and not run (at all!) in mine. Also, as I stated in the commit comments, the "buffering percentage == 0 means there's no buffering" condition is playing against us.

I'm going to analyze where that code comes from (what is its purpose) and try to improve it.

@eocanha
Copy link
Member

eocanha commented Apr 29, 2024

I've realized that the behaviour is very different depending if you use playbin2 for regular playback or playbin3 (by setting the export WEBKIT_GST_USE_PLAYBIN3=1 environment variable). I realized I had been using playbin3 all this time. With playbin2 I reproduced your issue.

I've applied some more corrections that only are into effect for playbin2 (your case). I've tested both variants with successful results here. Could you please try the latest version of the eocanha-debug-148 branch?

@pradeep-raveendranpillai-infosys
Copy link
Author

Thanks, Enrique.

I tested with your changes and the issue seems to be fixed. But, I see the same video stuttering happening when I do a skip/jump ( pressing >> option on the navigation bar of CNN ).
Also I noticed that the video is taking ~ 5 seconds longer to load initially.

@eocanha
Copy link
Member

eocanha commented Apr 30, 2024

Also I noticed that the video is taking ~ 5 seconds longer to load initially.

That's because the buffering algorithm was screwed for playbin2 and wasn't waiting at all to have the buffer complete. Now the buffer needs to be actually complete to start playback, and that can take time. You can reduce the percentage on this line to effectively reduce the buffer size and make things a bit more agile, at the expense of bumps when the network conditions are worse.

I've experienced the stuttering you mention after seeks, and sometimes even at the start. It's partially caused by sudden changes between 0% to 100% in the queue2 + playpump + multiqueue corrected joint level, where queue2 was at 0% but playpump was at 100%. I've added a small change to avoid corrections in case queue2 is at 0% (committed to the branch), but some small stuttering still happens because queue2 alternates between 0 and 100% very quickly (0.001s). I still don't have a good explanation about why this happens.

Would the amount of stuttering that is remaining be "acceptabe enough" for you at this point up to the point of considering this a good solution?

Another thing you could try is to use playbin3, by setting the environment variable I mentioned yesterday. Let me know if that may be a better alternative for you.

@pradeep-raveendranpillai-infosys
Copy link
Author

Even with your latest commit, I am able to see the stuttering happening after a seek and it still doesn't look good.
I even tried with playbin3, there also I could see the stuttering after a seek, though behavior is slightly better when compared to playbin, but is still not good enough.

@eocanha
Copy link
Member

eocanha commented May 2, 2024

Could you please provide logs with the latest changes for the case of seek? Thanks in advance.

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented May 3, 2024

Please find the log here
log.3may.2.txt

Today while testing, once I saw that after seeking, the video is stuck and never progresses. The log is attached here
log.3may.3.txt

@eocanha
Copy link
Member

eocanha commented May 9, 2024

I've updated (force-pushed) the eocanha-debug-148 branch with changes that...

  • Use 80% as the "buffer full" condition
  • Use a moving average to smooth the buffer level variability, with some tweaks: The average is reset to 0% on seeks (to ensure rebuffering) and to 100% if a single 100% peak appears (because when queue2 is actually saturated and the pipeline is paused, no more buffering messages will arrive and it won't be possible to get out of the "buffer not full" condition anymore. This will effectively make buffer full to be immediately considered, but buffer draining will take some time (until the average lowers itself).
  • Use the buffering level correction in more places.
  • IMPORTANT: Disallow more that one call to play() and any call to pause() if the environment variable DEBUG_ONLY_ALLOW_FIRST_PLAY=1 is defined. Try these changes first with it defined (you only will be able to play one video on each WPEFramework launch!) and if playback and seek work fine for you, then undefine it. If a lot of suttering or even a permanent stall happens without the variable, then the problem is the webapp JS code issuing play() and pause() calls on its own, which interfere with the buffering mechanism and screw up playback. You should review the webapp in that case. Maybe there's some legacy workaround in the JS app that shouldn't be there.

All these changes mess a lot with the original code. I'm going to start to try to clean them up and even discard those that aren't actually needed (the extra play()/pause() calls by the webapp were really screwing things up during my tests).

Let me know how these changes behave on your side and feel free to provide a new log if they don't work fine. I've observerd a smooth behaviour when network bandwidth isn't limited and buffering times (freezes for initial buffering) of some seconds when it's limited to 16000 Kbps, but that seems reasonable to me.

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented May 13, 2024

I tested both with DEBUG_ONLY_ALLOW_FIRST_PLAY and without DEBUG_ONLY_ALLOW_FIRST_PLAY defined. In both cases I could see the issue happening. Attaching the logs.
The issue was more reproducible with the url https://clips-mp4-aka.warnermediacdn.com/cnn/clips/2024-04/1502030-3a5a0e2b43b54391841610ad555354e4/mp4/cms3-CNN-darkness-kerrville-texas-rosa-flores-solar-eclipse-2024-april-8-nasa-vpx-primary-356926-1502030-1920x1080_8000k.mp4

log.13may.1.txt

  • this is WITHOUT the flag defined. I could see the stuttering after a seek.

log.13may.flag.enabled.2.txt

  • this is WITH the flag defined. I could see the stuttering after a seek, as well as during the initial few seconds as well !!!

The network speed was > 25Mbps when I tested this.

@eocanha
Copy link
Member

eocanha commented May 22, 2024

These days I've been working on a hysteresis mechanism for buffering and other improvements, such as unified calculation of m_isBuffering and m_bufferingPercentage, so buffering/not-buffering detection is more consistent. Things work reasonably well here thanks to it (with the patch to ignore subsequent pause()/play() calls by the app) on playbin2. There's still something weird on playbin3 that I'm currently debugging:

After seek, sometimes, the player goes "officially" into playing state (spinner disappears), and the GStreamer pipeline follows suit, but there's not enough data ready (buffer isn't full yet), so the pipeline underruns and stalls for some seconds until the data arrives and the picture starts moving. During all that time, WebKit thinks that the video has been playing.

I haven't pushed my local changes to the remote test branch yet.

@eocanha
Copy link
Member

eocanha commented May 29, 2024

Although I've been kept working on this full time, I haven't made much progress since the last week report. I have added code to pause the pipeline on seek (so that it doesn't try to blindly continue to play after the seek completes, and instead evaluates the buffering state and only continues when the buffer level is enough), but I still have the issue of the pipeline going to playing state (this includes Nexus gst elements acknowledging that they're in playing state) but Nexus not actually animating the video. There are unexplainable 2.5s of delay (in the worst case) in the audiodecoder and additional 2.5s in the multiqueue that is after it. You can see those delays in the 2nd, 3rd and 4th blocks of these logs generated by my probes (look at the gst log timestamps at the begining of each line):

0:00:06.765667931  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:06.767089803  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:06.767249385  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:09.283432960  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:09.283495845  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:09.283530584  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.660020833, DUR=0:00:00.021333334
0:00:09.283838124  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.660020833, DUR=0:00:00.021333334

0:00:06.769856292  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:06.771065141  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:09.283633505  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:11.793934360  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:11.794002801  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:11.794042651  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.681354166, DUR=0:00:00.021333333
0:00:11.794119573  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.681354166, DUR=0:00:00.021333333

0:00:06.771234389  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:06.772347466  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:11.800021633  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:14.312399258  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:14.312458848  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:14.312491773  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.702687500, DUR=0:00:00.021333333
0:00:14.312805872  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.702687500, DUR=0:00:00.021333333

0:00:06.777885297  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:06.778992856  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:14.312591843  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:16.825125639  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:16.825196970  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:16.825230747  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.724020833, DUR=0:00:00.021333334
0:00:16.825329929  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.724020833, DUR=0:00:00.021333334

0:00:06.780296994  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:06.781315188  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:16.825354150  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:16.886185658  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:16.886255915  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:16.886292136  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.745354166, DUR=0:00:00.021333333
0:00:16.886391022  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.745354166, DUR=0:00:00.021333333

0:00:06.781461068  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:06.782349789  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:16.886402133  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:16.886590793  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:16.886632866  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:16.886662384  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.766687500, DUR=0:00:00.021333333
0:00:16.887176664  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.766687500, DUR=0:00:00.021333333

0:00:06.784228817  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:06.785175460  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:16.886773084  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:16.886883636  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:16.886919635  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:16.886945523  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.788020833, DUR=0:00:00.021333334
0:00:16.887241402  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.788020833, DUR=0:00:00.021333334

0:00:06.785324895  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-sink: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:06.786384160  6131 0x8b105a20 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudfilter0:brcm-audfilter-src: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:16.887011150  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:sink: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:16.887147924  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### brcmaudiodecoder0:src: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:16.887178145  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:sink_1: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:16.887203848  6131 0xac305928 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3257:operator(): ### streamsynchronizer0:src_1: PTS=0:00:11.809354166, DUR=0:00:00.021333333
0:00:16.887267883  6131 0xab9c64c8 DEBUG      webkitmediaplayer Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3253:operator(): ### brcmaudiosink0:sink: [DROPPED] PTS=0:00:11.809354166, DUR=0:00:00.021333333

The only "explanation" that I've been able to find is that the retry loop in gst_brcm_audio_decoder.c:2709:gst_brcm_audio_decoder_chain() is looping, exhausting its max 82+1 retry iterations and erroring out with the "audio buffer limiting taking longer than expected" warning. I don't know the inner cause for this, because Nexus is sort of a black box for me.

But anyway, even though there's this huge ugly delay after seek, stuttering isn't happening anymore for me. If you wan't I can try to clean all that I have and push it again to the test branch for you to test.

@eocanha
Copy link
Member

eocanha commented May 30, 2024

I've updated the eocanha-debug-148 branch with my latest changes. It's the most I've been able to get before bumping with the Broadcom Nexus black box, which doesn't give any explanation about why the mysterious 5s delay is happening after seeks.

This branch still has the commit to disable pause() and play() calls. If you enable them, stuttering will appear, but the decision to make those pause() and play() calls comes from the web app and is out of the control of the browser (if the app wants to pause/play multiple times and create stuttering, there's nothing we can do).

If these changes provide improvements good enough, I can start to upstream them and bring them back to the official wpe-2.38 branch.

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Jun 3, 2024

Thanks, Enrique.
I did limited testing with the changes in your debug branch and below are my observations.

Play and Seek operations

WITHOUT DEBUG_ONLY_ALLOW_FIRST_PLAY defined:
There is no video stuttering during initial playback as well as after a seek. The delay after a seek seems acceptable. Log for the same is - log.play.seek.working.txt

WITH DEBUG_ONLY_ALLOW_FIRST_PLAY defined:
There is no video stuttering during initial playback. But, after a seek video freezes and never recovers. Log for the same is -
log.DEBUG_ONLY_ALLOW_FIRST_PLAY.seek.not.working.txt

Playback under low network bandwidth condition (2Mbps)

WITHOUT DEBUG_ONLY_ALLOW_FIRST_PLAY defined:
Video doesn't pause for long enough while buffering. Rather it plays slowly i.e. it pauses and resumes too quickly giving a feeling of slow speed playback. Audio drops are heard. This behavior is not good. Log for the same is -
log.low.bandwidth.notworking.txt

WITH DEBUG_ONLY_ALLOW_FIRST_PLAY defined:
Works fine. Video pauses wile buffering and then resumes. Log for the same is -
log.DEBUG_ONLY_ALLOW_FIRST_PLAY.low.bandwidth.working.txt

@eocanha
Copy link
Member

eocanha commented Jun 3, 2024

Could you please run the "Play and seek operations with DEBUG_ONLY_ALLOW_FIRST_PLAY defined" case with all the debug levels you laready had but, in addition to that, with "webkitmediaplayer:TRACE"? There are some gst messages in that level that I would need in order to understand what's happening and why updateStates() doesn't decide to change the pipeline to playing state again.

@pradeep-raveendranpillai-infosys
Copy link
Author

Changed debug level to 7 (trace) in /etc/WPEFramework/plugins/WebKitBrowser.json
"gstdebug":"3,GST_STATES:3,GST_PIPELINE:4,GST_EVENT:4,GST_BUS:4,webkit*:7,brcm*:5,westerosink*:5"

The log file for the play scenario with DEBUG_ONLY_ALLOW_FIRST_PLAY defined is given below

log.seek.DEBUG_ONLY_ALLOW_FIRST_PLAY.tracelevel.1.txt

@eocanha
Copy link
Member

eocanha commented Jun 3, 2024

An unfortunate mix of events (pipeline forced to pause before seek on purpose, but buffering level evaluating to 100% for some reason after that) made the m_isBuffering true --> false transition to never be detected by updateStates(). That's why playback never resumed.
I've pushed a patch that, on top of forcing the pause of the pipeline before seek, forces re-evaluation of m_isBuffering to true, ensuring (in theory) that the true --> false transition will be detected this time.
Please, run the same test case as before again (and capture logs in case it doesn't work as expected). Let's hope that this time it works...

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Jun 5, 2024

Tested with DEBUG_ONLY_ALLOW_FIRST_PLAY defined.

Video starts playing without any stuttering, but after a seek it still freezes and never recovers. Log for the same is -
log.5jun.DEBUG_ONLY_ALLOW_FIRST_PLAY.SEEK.DEBUG.txt

With low n/w conditions (4Mbps) video pauses while buffering and then resumes which is working as expected. But after a seek video freezes and never recovers. Log for the same is -
log.5jun.DEBUG_ONLY_ALLOW_FIRST_PLAY.lowbandwidth.SEEK.DEBUG.txt

For both the logs I have stopped capturing after 10 -15 seconds to limit the log file size, as size > 10MB cant be uploaded here. But the video never recovers for both of the above scenarios, i.e. even after a couple of minutes.

@eocanha
Copy link
Member

eocanha commented Jun 6, 2024

(Sorry, wrong comment, I submitted here a comment that was intended for another issue)

@eocanha
Copy link
Member

eocanha commented Jun 13, 2024

I've updated the eocanha-debug-148 branch with a new change that might prevent the freeze after the seek, by "sinking" the m_isBuffering value to true, so the true to false change is properly detected when buffering is complete. This is something that wasn't happening in the latest test case you reported.

Please retest and let me know any problem that you find this time. Thanks!

@pradeep-raveendranpillai-infosys
Copy link
Author

Okay. Hope the regression issues reported above will also be addressed.

@pradeep-raveendranpillai-infosys
Copy link
Author

Any update on the fix for the above mentioned regressions?

@eocanha
Copy link
Member

eocanha commented Jul 2, 2024

I've been out of office last week and retook the task yesterday. The Deezer log revealed that the code to manage getting back to play after buffering wasn't having into account voluntary pauses by the user (m_playbackRatePausedState == PlaybackRatePausedState::ManuallyPaused). I added a condition to have that into account (locally, not pushed yet) and now need to check if I can reproduce the issue and if that fix works.
I'm also having a look at the CNN log.

@eocanha
Copy link
Member

eocanha commented Jul 4, 2024

I've updated the eocanha-debug-148 branch to include a new commit that should fix the two regressions. Please retest.

Note that the branch has been force-updated. I'm locally working with code adapted to the Quirks framework and have ported the patches to a branch that is still based on ifdefs in the simplest way possible (only using ifdefs when the original code would ask the Quirks framework). I haven't compiled that non-Quirks branch here because I don't want to trigger a full rebuild just for that. It should work.

Now I still have to do all the upstream reworks asked by the reviewers, fix the layout tests there and bring back any fix resulting from that. Dealing with 3 different branches/environments is starting to be messy...

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Jul 8, 2024

With above changes, I see video stuttering for CNN video after a seek operation. Also there is audio stuttering in Deezer app when playing podcast music (even without seek). The logs for the same is attached. Didn't continue with further testing.
log.cnn.8jul.txt
log.deezer.8jul.txt

eocanha added a commit to eocanha/WebKit that referenced this issue Jul 10, 2024
https://bugs.webkit.org/show_bug.cgi?id=275683

Reviewed by NOBODY (OOPS!).

The usage of a fixed buffering level to evaluate the need for buffering
results in a too unstable behaviour, with quick changes between states
that may create stuttering.

This commit adds hysteresis to the buffering level, with low and high
watermark levels that trigger "buffering needed" (when below the low
watermark), "buffering completed" (when above high watermark) and "same
state as before" when the level is between both marks.

In addition to that, the pipeline is automatically paused on a seek when
working on stream mode (using GstQueue2 for partial in-memory buffering
instead of using GstDownload for full on-disk download of the media).
This is because, when seeking, rebuffering must occur from scratch to
get the data for the new target position, and buffering level starts
from 0% in that case, which means that buffering is needed and the
pipeline must be paused. Both the m_Buffering flag and
m_bufferingPercentage are immediately forced to true and 0%, respectively.
The previous values (see explanation below) are also set to the same
values by using the new resetHistory parameter in updateBufferingStatus().
This makes sure that the "end of buffering" condition can be properly
detected.

The buffering status and buffering level computation has been
centralized in updateBufferingStatus(). Both the status and the level
now store the last value, so it's possible to check if there's been any
difference on them and to decide here on the hysteresis status
evolution.

updateStates() is where the consequences of buffering changes happen.
This method now relies in the status and level updates explained in the
previous paragraph. In the specific case of an async change, the current
values for m_isBuffering and m_bufferingPercentage are ignored (previous
ones are used). This is to be able to detect significant changes in the
hysteresis (watermark level crossing) after the async change has
completed. Otherwise, we would be detecting those crossings in a moment
where nothing can be done (pipeline state changes are ignored can can't
be enforced during async state changes).

Some extra improvements have been added to adapt to the special
circumstances of Broadcom devices, where the PlayPump Nexus component
can store a lot of data which is hidden to the vanilla buffering
algorithm. Now that data is had into account to compute the realistic
buffering level. Also, more agile low/high watermarks of 20% and 80% are
used for buffering in the case of playbin2 in stream buffering mode on
Broadcom.

20-80% levels for low/high watermark are now used on all devices
(Broadcom and not Broadcom), since usage tests proved that this makes
the buffering more agile also on Raspberry Pi, for instance.

All these changes are compatible with the Quirks framework. A new
needsBufferingPercentageCorrection() method has been added to enable the
extra buffering logic (which corrects the queue2 buffering level with the
buffer levels of PlayPump and multiqueue) on the platforms that use Nexus.
All the code to implement that logic has been hidden in the
GStreamerQuirkBroadcomBase class, from which both GStreamerQuirkBcmNexus
and GStreamerQuirkBroadcom inherit.

That code needs some elements that in principle would be very coupled with
MediaPlayerPrivateGStreamer, such as vidfilter, queue2, multiqueue and a
MovingAverage to smooth buffering levels. To avoid that coupling, they
are stored in an opaque GStreamerQuirkState, stored by the player private
but implemented by a GStreamerQuirkBroadcomBaseState subclass that only
GStreamerQuirkBroadcomBase knows how to interpret (by casting after
ensuring that the casting is legal).

There's also the problem that multiple competing quirks can be installing
at the same time, but all this buffering percentage correction code must
only be run by one (only one!) of them. To solve that, the quirks state
is configured with an owner quirk, and only that owner can use it. The
rest of the competing quirks quich are not the owner must bail out and
return default results on their buffering percentage correction method
calls.

See: WebPlatformForEmbedded/WPEWebKit#1309

* Source/WebCore/platform/SourcesGStreamer.txt: Added GStreamerQuirkBroadcomBase.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:
(WebCore::MediaPlayerPrivateGStreamer::play): Make code compatible with InitiallyPaused.
(WebCore::MediaPlayerPrivateGStreamer::doSeek): Pause pipeline and reset buffering level to 0% in case we're operating in stream mode.
(WebCore::MediaPlayerPrivateGStreamer::queryBufferingPercentage): Get the buffering percentage from the most relevant element and delegate to the quirks.
(WebCore::MediaPlayerPrivateGStreamer::fillTimerFired): Clarify that this method is only used in on-disk buffering. Rely on queryBufferingPercentage() now, instead of manually getting the value from here.
(WebCore::MediaPlayerPrivateGStreamer::handleMessage): Delegate to the quirks to store/delete references to specific elements in the quirks state.
(WebCore::MediaPlayerPrivateGStreamer::processBufferingStats): Delegate to the quierks to apply buffering percentage corrections on platforms that need them.
(WebCore::MediaPlayerPrivateGStreamer::updateBufferingStatus): Update the values of m_wasBuffering, m_isBuffering, m_previousBufferingPercentage, m_bufferingPercentage and m_didDownloadFinish. The first 4 attributes should *ONLY* be modified from this method, in order to guarantee coherency. The only *EXCEPTION* to this rule is the delay which can happen in updateStates(). The new resetHistory parameter sets the value both in the previous value family of attributes and in the current value family of variables.
(WebCore::MediaPlayerPrivateGStreamer::updateStates): Assume that m_wasBuffering, etc. have been precomputed by updateBufferingStatus() before updateStates() is called. In the case of an async state change, delay m_isBuffering and m_bufferingPercentage "to the past" (m_wasBuffering and m_previousBufferingPercentage), so that any change on them can be detected on the next iteration.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h: Added new m_wasBuffering and m_previousBufferingPercentage attributes to store previous values of m_isBuffering and m_bufferingPercentage and ease detection of changes. Added quirks state.
(WebCore::MediaPlayerPrivateGStreamer::shouldDownload): Needed by quirks.
(WebCore::MediaPlayerPrivateGStreamer::setQuirkState): Configure a quirks state on the player private.
(WebCore::MediaPlayerPrivateGStreamer::quirkState): Get a quirks state from the player private.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkBcmNexus.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkFake.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkAmLogic.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBcmNexus.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcom.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.cpp: Added. Base class for GStreamerQuirkBcmNexus and GStreamerQuirkBroadcom.
(WebCore::GStreamerQuirkBroadcomBase::GStreamerQuirkBroadcomBase): Constructor.
(WebCore::GStreamerQuirkBroadcomBase::queryBufferingPercentage const): Get the buffering percentage from Queue2 if present and the player shouldn't download (streaming mode).
(WebCore::GStreamerQuirkBroadcomBase::correctBufferingPercentage const): On systems using PlayPump (eg: Broadcom Nexus), correct the buffering percentage with the data stored in multiqueue and PlayPump in order to make the buffering percentage more realistic. Uses the MovingAverage.
(WebCore::GStreamerQuirkBroadcomBase::resetBufferingPercentage const): Sets the percentage to a given value in the MovingAverage.
(WebCore::GStreamerQuirkBroadcomBase::setupBufferingPercentageCorrection const): Gets/deletes references to vidfilter, multiqueue and queue2 in the quirks state.
(WebCore::GStreamerQuirkBroadcomBase::isEnsuredOwnedState const): Creates the quirk state if not present (if it's still assigned to the GStreamerQuirkState superclass), assigning it to an instance of the GStreamerQuirkBroadcomBaseState subclass and setting the current GStreamerQuirkBroadcomBase implementation (GStreamerQuirkBcmNexus or GStreamerQuirkBroadcom, first come first served) as owner. If the state had been initialized with a subclass before, returns false, so the caller can bail out.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.h: Added.
(WebCore::GStreamerQuirkBroadcomBase::needsBufferingPercentageCorrection const): True for this class and derived ones.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::MovingAverage): Initialize an array of "length" number of elements.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::reset): Reset all the values to a given value (usually zero).
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::accumulate): Insert a new value in the array and recompute the moving average.
(WebCore::GStreamerQuirkBroadcomBase::GStreamerQuirkBroadcomBaseState::GStreamerQuirkBroadcomBaseState): Concrete GStreamerQuirkState that stores all the elements and the MovingAverage associated to a specific MediaPlayerPrivateGStreamer that GStreamerQuirkBroadcomBase needs to do its job. This avoids getting MediaPlayerPrivateGStreamer dirty with extra attributes that are only relevant for platforms with quirks.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRealtek.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.cpp: Added new methods.
(WebCore::GStreamerQuirksManager::needsBufferingPercentageCorrection const): True if any configured quirk needs it.
(WebCore::GStreamerQuirksManager::queryBufferingPercentage const): Forward query request to any configured quirk that can fulfill it.
(WebCore::GStreamerQuirksManager::correctBufferingPercentage const): Forward correction request to any configured quirk that can fulfill it.
(WebCore::GStreamerQuirksManager::resetBufferingPercentage const): Ditto, but for reset.
(WebCore::GStreamerQuirksManager::setupBufferingPercentageCorrection const): Ditto, but for setup. The first quirk subclass that sets a quirk state in this call or any of the others will be the *only* subclass that will operate the buffer percentage correnction, and the rest will bail out. The first one coming is the only one that will work from that moment on. The rest will be incompatible with that specific configured quirk state and will bail out.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.h:
(WebCore::GStreamerQuirkBase::GStreamerQuirkState:::m_owner): Pointer to identify the specific GStreamerQuirk instance that owns the state. This pointer is *not* used to access the quirk.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::GStreamerQuirkState): Constructor. No owner needed (on purpose, to mark the "unconfigured" state.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::isOwnedBy): True if owned by the specific GStreamerQuirk passed as parameter.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::isOwned): True if owned by any GStreamerQuirk. False if still unconfigured/unowned.
(WebCore::GStreamerQuirk::needsBufferingPercentageCorrection const): Default empty implementation.
(WebCore::GStreamerQuirk::queryBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::correctBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::resetBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::setupBufferingPercentageCorrection const): Ditto.
eocanha added a commit to eocanha/WebKit that referenced this issue Jul 10, 2024
https://bugs.webkit.org/show_bug.cgi?id=275683

Reviewed by NOBODY (OOPS!).

The usage of a fixed buffering level to evaluate the need for buffering
results in a too unstable behaviour, with quick changes between states
that may create stuttering.

This commit adds hysteresis to the buffering level, with low and high
watermark levels that trigger "buffering needed" (when below the low
watermark), "buffering completed" (when above high watermark) and "same
state as before" when the level is between both marks.

In addition to that, the pipeline is automatically paused on a seek when
working on stream mode (using GstQueue2 for partial in-memory buffering
instead of using GstDownload for full on-disk download of the media).
This is because, when seeking, rebuffering must occur from scratch to
get the data for the new target position, and buffering level starts
from 0% in that case, which means that buffering is needed and the
pipeline must be paused. Both the m_Buffering flag and
m_bufferingPercentage are immediately forced to true and 0%, respectively.
The previous values (see explanation below) are also set to the same
values by using the new resetHistory parameter in updateBufferingStatus().
This makes sure that the "end of buffering" condition can be properly
detected.

The buffering status and buffering level computation has been
centralized in updateBufferingStatus(). Both the status and the level
now store the last value, so it's possible to check if there's been any
difference on them and to decide here on the hysteresis status
evolution.

updateStates() is where the consequences of buffering changes happen.
This method now relies in the status and level updates explained in the
previous paragraph. In the specific case of an async change, the current
values for m_isBuffering and m_bufferingPercentage are ignored (previous
ones are used). This is to be able to detect significant changes in the
hysteresis (watermark level crossing) after the async change has
completed. Otherwise, we would be detecting those crossings in a moment
where nothing can be done (pipeline state changes are ignored can can't
be enforced during async state changes).

Some extra improvements have been added to adapt to the special
circumstances of Broadcom devices, where the PlayPump Nexus component
can store a lot of data which is hidden to the vanilla buffering
algorithm. Now that data is had into account to compute the realistic
buffering level. Also, more agile low/high watermarks of 20% and 80% are
used for buffering in the case of playbin2 in stream buffering mode on
Broadcom.

20-80% levels for low/high watermark are now used on all devices
(Broadcom and not Broadcom), since usage tests proved that this makes
the buffering more agile also on Raspberry Pi, for instance.

All these changes are compatible with the Quirks framework. A new
needsBufferingPercentageCorrection() method has been added to enable the
extra buffering logic (which corrects the queue2 buffering level with the
buffer levels of PlayPump and multiqueue) on the platforms that use Nexus.
All the code to implement that logic has been hidden in the
GStreamerQuirkBroadcomBase class, from which both GStreamerQuirkBcmNexus
and GStreamerQuirkBroadcom inherit.

That code needs some elements that in principle would be very coupled with
MediaPlayerPrivateGStreamer, such as vidfilter, queue2, multiqueue and a
MovingAverage to smooth buffering levels. To avoid that coupling, they
are stored in an opaque GStreamerQuirkState, stored by the player private
but implemented by a GStreamerQuirkBroadcomBaseState subclass that only
GStreamerQuirkBroadcomBase knows how to interpret (by casting after
ensuring that the casting is legal).

There's also the problem that multiple competing quirks can be installing
at the same time, but all this buffering percentage correction code must
only be run by one (only one!) of them. To solve that, the quirks state
is configured with an owner quirk, and only that owner can use it. The
rest of the competing quirks quich are not the owner must bail out and
return default results on their buffering percentage correction method
calls.

See: WebPlatformForEmbedded/WPEWebKit#1309

* Source/WebCore/platform/SourcesGStreamer.txt: Added GStreamerQuirkBroadcomBase.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:
(WebCore::MediaPlayerPrivateGStreamer::play): Make code compatible with InitiallyPaused.
(WebCore::MediaPlayerPrivateGStreamer::doSeek): Pause pipeline and reset buffering level to 0% in case we're operating in stream mode.
(WebCore::MediaPlayerPrivateGStreamer::queryBufferingPercentage): Get the buffering percentage from the most relevant element and delegate to the quirks.
(WebCore::MediaPlayerPrivateGStreamer::fillTimerFired): Clarify that this method is only used in on-disk buffering. Rely on queryBufferingPercentage() now, instead of manually getting the value from here.
(WebCore::MediaPlayerPrivateGStreamer::handleMessage): Delegate to the quirks to store/delete references to specific elements in the quirks state.
(WebCore::MediaPlayerPrivateGStreamer::processBufferingStats): Delegate to the quierks to apply buffering percentage corrections on platforms that need them.
(WebCore::MediaPlayerPrivateGStreamer::updateBufferingStatus): Update the values of m_wasBuffering, m_isBuffering, m_previousBufferingPercentage, m_bufferingPercentage and m_didDownloadFinish. The first 4 attributes should *ONLY* be modified from this method, in order to guarantee coherency. The only *EXCEPTION* to this rule is the delay which can happen in updateStates(). The new resetHistory parameter sets the value both in the previous value family of attributes and in the current value family of variables.
(WebCore::MediaPlayerPrivateGStreamer::updateStates): Assume that m_wasBuffering, etc. have been precomputed by updateBufferingStatus() before updateStates() is called. In the case of an async state change, delay m_isBuffering and m_bufferingPercentage "to the past" (m_wasBuffering and m_previousBufferingPercentage), so that any change on them can be detected on the next iteration.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h: Added new m_wasBuffering and m_previousBufferingPercentage attributes to store previous values of m_isBuffering and m_bufferingPercentage and ease detection of changes. Added quirks state.
(WebCore::MediaPlayerPrivateGStreamer::shouldDownload): Needed by quirks.
(WebCore::MediaPlayerPrivateGStreamer::setQuirkState): Configure a quirks state on the player private.
(WebCore::MediaPlayerPrivateGStreamer::quirkState): Get a quirks state from the player private.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkBcmNexus.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkFake.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkAmLogic.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBcmNexus.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcom.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.cpp: Added. Base class for GStreamerQuirkBcmNexus and GStreamerQuirkBroadcom.
(WebCore::GStreamerQuirkBroadcomBase::GStreamerQuirkBroadcomBase): Constructor.
(WebCore::GStreamerQuirkBroadcomBase::queryBufferingPercentage const): Get the buffering percentage from Queue2 if present and the player shouldn't download (streaming mode).
(WebCore::GStreamerQuirkBroadcomBase::correctBufferingPercentage const): On systems using PlayPump (eg: Broadcom Nexus), correct the buffering percentage with the data stored in multiqueue and PlayPump in order to make the buffering percentage more realistic. Uses the MovingAverage.
(WebCore::GStreamerQuirkBroadcomBase::resetBufferingPercentage const): Sets the percentage to a given value in the MovingAverage.
(WebCore::GStreamerQuirkBroadcomBase::setupBufferingPercentageCorrection const): Gets/deletes references to vidfilter, multiqueue and queue2 in the quirks state.
(WebCore::GStreamerQuirkBroadcomBase::isEnsuredOwnedState const): Creates the quirk state if not present (if it's still assigned to the GStreamerQuirkState superclass), assigning it to an instance of the GStreamerQuirkBroadcomBaseState subclass and setting the current GStreamerQuirkBroadcomBase implementation (GStreamerQuirkBcmNexus or GStreamerQuirkBroadcom, first come first served) as owner. If the state had been initialized with a subclass before, returns false, so the caller can bail out.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.h: Added.
(WebCore::GStreamerQuirkBroadcomBase::needsBufferingPercentageCorrection const): True for this class and derived ones.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::MovingAverage): Initialize an array of "length" number of elements.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::reset): Reset all the values to a given value (usually zero).
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::accumulate): Insert a new value in the array and recompute the moving average.
(WebCore::GStreamerQuirkBroadcomBase::GStreamerQuirkBroadcomBaseState::GStreamerQuirkBroadcomBaseState): Concrete GStreamerQuirkState that stores all the elements and the MovingAverage associated to a specific MediaPlayerPrivateGStreamer that GStreamerQuirkBroadcomBase needs to do its job. This avoids getting MediaPlayerPrivateGStreamer dirty with extra attributes that are only relevant for platforms with quirks.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRealtek.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.cpp: Added new methods.
(WebCore::GStreamerQuirksManager::needsBufferingPercentageCorrection const): True if any configured quirk needs it.
(WebCore::GStreamerQuirksManager::queryBufferingPercentage const): Forward query request to any configured quirk that can fulfill it.
(WebCore::GStreamerQuirksManager::correctBufferingPercentage const): Forward correction request to any configured quirk that can fulfill it.
(WebCore::GStreamerQuirksManager::resetBufferingPercentage const): Ditto, but for reset.
(WebCore::GStreamerQuirksManager::setupBufferingPercentageCorrection const): Ditto, but for setup. The first quirk subclass that sets a quirk state in this call or any of the others will be the *only* subclass that will operate the buffer percentage correnction, and the rest will bail out. The first one coming is the only one that will work from that moment on. The rest will be incompatible with that specific configured quirk state and will bail out.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.h:
(WebCore::GStreamerQuirkBase::GStreamerQuirkState:::m_owner): Pointer to identify the specific GStreamerQuirk instance that owns the state. This pointer is *not* used to access the quirk.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::GStreamerQuirkState): Constructor. No owner needed (on purpose, to mark the "unconfigured" state.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::isOwnedBy): True if owned by the specific GStreamerQuirk passed as parameter.
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::isOwned): True if owned by any GStreamerQuirk. False if still unconfigured/unowned.
(WebCore::GStreamerQuirk::needsBufferingPercentageCorrection const): Default empty implementation.
(WebCore::GStreamerQuirk::queryBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::correctBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::resetBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::setupBufferingPercentageCorrection const): Ditto.
@eocanha
Copy link
Member

eocanha commented Jul 11, 2024

Analyzed CNN video stuttering after seek logs. Apparently, the stuttering in the CNN case is legitimately caused by network data starving which brings the buffer below the low watermark level. The Deezer case, on the other hand, is caused by big 0-100% variations in the buffering level. The Broadcom buffer percentage correction isn't applied in this case because Deezer is an audio-only service, and the code looks for vidfilter (not present). I can work on trying to apply the same corrections when only audfilter is present.

@pradeep-raveendranpillai-infosys, I have a question: Would it be possible for you to upgrade your wpe-2.38 branch to support the Quirks framework (the latest Quirks commits in wpe-2.38)? Maintaining a non-quirks version of the patch is starting to be complex, since the upstream version of the patch is more and more invested in Quirks as the patch evolves, and the more changes there, the more difficul it is to backport the changes to a non-quirks version downstream.

@eocanha
Copy link
Member

eocanha commented Jul 11, 2024

Also... I've just realized that the last version I pushed (without Quirks support) wasn't even compiling because of this and this. Sorry about that! (It was because I always worked with the Quirks support version here, and adapted the code to non-Quirks blindly). I've now pushed a version that builds.

So... I don't know exactly what version you tried to get those CNN and Deezer problems on the "8jul" logs.

@pradeep-raveendranpillai-infosys
Copy link
Author

@eocanha I am sorry, upgrading to latest wpe-2.38 may not be possible immediately but eventually it will be done. Sorry to know that you have to do double work here because of that.

Regarding the compilation errors, I had encountered it and I had corrected it myself then. I just forgot to update that in my previous comment.

eocanha added a commit to eocanha/WebKit that referenced this issue Jul 29, 2024
https://bugs.webkit.org/show_bug.cgi?id=275683

Reviewed by NOBODY (OOPS!).

The usage of a fixed buffering level to evaluate the need for buffering
results in a too unstable behaviour, with quick changes between states
that may create stuttering.

This commit adds hysteresis to the buffering level, with low and high
watermark levels that trigger "buffering needed" (when below the low
watermark), "buffering completed" (when above high watermark) and "same
state as before" when the level is between both marks.

In addition to that, the pipeline is automatically paused on a seek when
working on stream mode (using GstQueue2 for partial in-memory buffering
instead of using GstDownload for full on-disk download of the media).
This is because, when seeking, rebuffering must occur from scratch to
get the data for the new target position, and buffering level starts
from 0% in that case, which means that buffering is needed and the
pipeline must be paused. Both the m_isBuffering flag and
m_bufferingPercentage are immediately forced to true and 0%, respectively.
The previous values (see explanation below) are also set to the same
values by using the new resetHistory parameter in updateBufferingStatus().
This makes sure that the "end of buffering" condition can be properly
detected.

The buffering status and buffering level computation has been
centralized in updateBufferingStatus(). Both the status and the level
now store the last value, so it's possible to check if there's been any
difference on them and to decide here on the hysteresis status
evolution.

updateStates() is where the consequences of buffering changes happen.
This method now relies in the status and level updates explained in the
previous paragraph. In the specific case of an async change, the current
values for m_isBuffering and m_bufferingPercentage are ignored (previous
ones are used). This is to be able to detect significant changes in the
hysteresis (watermark level crossing) after the async change has
completed. Otherwise, we would be detecting those crossings in a moment
where nothing can be done (pipeline state changes are ignored can can't
be enforced during async state changes).

Some extra improvements have been added to adapt to the special
circumstances of Broadcom devices, where the PlayPump Nexus component
can store a lot of data which is hidden to the vanilla buffering
algorithm. Now that data is had into account to compute the realistic
buffering level. Also, more agile low/high watermarks of 20% and 80% are
used for buffering in the case of playbin2 in stream buffering mode on
Broadcom.

20-80% levels for low/high watermark are now used on all devices
(Broadcom and not Broadcom), since usage tests proved that this makes
the buffering more agile also on Raspberry Pi, for instance.

All these changes are compatible with the Quirks framework. A new
needsBufferingPercentageCorrection() method has been added to enable the
extra buffering logic (which corrects the queue2 buffering level with the
buffer levels of PlayPump and multiqueue) on the platforms that use Nexus.
All the code to implement that logic has been hidden in the
GStreamerQuirkBroadcomBase class, from which both GStreamerQuirkBcmNexus
and GStreamerQuirkBroadcom inherit.

That code needs some elements that in principle would be very coupled with
MediaPlayerPrivateGStreamer, such as vidfilter, queue2, multiqueue and a
MovingAverage to smooth buffering levels. To avoid that coupling, they
are stored in an opaque GStreamerQuirkState, stored by the player private
but implemented by a GStreamerQuirkBroadcomBaseState subclass that only
GStreamerQuirkBroadcomBase knows how to interpret (by casting after
ensuring that the casting is legal).

There's also the problem that multiple competing quirks can be installing
at the same time, but all this buffering percentage correction code must
only be run by one (only one!) of them. To allow the theoretical coexistence
of multiple quirk state, each quirk instance has one associated state, and
the player private maintains that correspondence using a HashMap indexed by
quirk. To ensure that only one quirk is run at each time, the family of methods
in GStreamerQuirksManager only forward the call to the first configured
GStreamerQuirk subclass that declares the need to apply corrections. Any other
configured subclass is ignored.

See: WebPlatformForEmbedded/WPEWebKit#1309

* Source/WebCore/platform/SourcesGStreamer.txt: Added GStreamerQuirkBroadcomBase.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:
(WebCore::MediaPlayerPrivateGStreamer::play): Make code compatible with InitiallyPaused.
(WebCore::MediaPlayerPrivateGStreamer::doSeek): Pause pipeline and reset buffering level to 0% in case we're operating in stream mode.
(WebCore::MediaPlayerPrivateGStreamer::queryBufferingPercentage): Get the buffering percentage from the most relevant element and delegate to the quirks.
(WebCore::MediaPlayerPrivateGStreamer::fillTimerFired): Clarify that this method is only used in on-disk buffering. Rely on queryBufferingPercentage() now, instead of manually getting the value from here.
(WebCore::MediaPlayerPrivateGStreamer::handleMessage): Delegate to the quirks to store/delete references to specific elements in the quirks state.
(WebCore::MediaPlayerPrivateGStreamer::processBufferingStats): Delegate to the quierks to apply buffering percentage corrections on platforms that need them.
(WebCore::MediaPlayerPrivateGStreamer::updateBufferingStatus): Update the values of m_wasBuffering, m_isBuffering, m_previousBufferingPercentage, m_bufferingPercentage and m_didDownloadFinish. The first 4 attributes should *ONLY* be modified from this method, in order to guarantee coherency. The only *EXCEPTION* to this rule is the delay which can happen in updateStates(). The new resetHistory parameter sets the value both in the previous value family of attributes and in the current value family of variables.
(WebCore::MediaPlayerPrivateGStreamer::updateStates): Assume that m_wasBuffering, etc. have been precomputed by updateBufferingStatus() before updateStates() is called. In the case of an async state change, delay m_isBuffering and m_bufferingPercentage "to the past" (m_wasBuffering and m_previousBufferingPercentage), so that any change on them can be detected on the next iteration.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h: Added new m_wasBuffering and m_previousBufferingPercentage attributes to store previous values of m_isBuffering and m_bufferingPercentage and ease detection of changes. Added quirks state.
(WebCore::MediaPlayerPrivateGStreamer::shouldDownload): Needed by quirks.
(WebCore::MediaPlayerPrivateGStreamer::setQuirkState): Configure a GStreamerQuirkState for a specific GStreamerQuirk on the player private (each quirk has its own state, and in theory there can be many quirk-state stored).
(WebCore::MediaPlayerPrivateGStreamer::quirkState): Get the quirks state associated to a specific quirk from the player private, or nullptr if there's no configured state for that quirk.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkBcmNexus.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkFake.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerHolePunchQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkAmLogic.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBcmNexus.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcom.h: Ditto. Inherit from base class.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.cpp: Added. Base class for GStreamerQuirkBcmNexus and GStreamerQuirkBroadcom.
(WebCore::GStreamerQuirkBroadcomBase::GStreamerQuirkBroadcomBase): Constructor.
(WebCore::GStreamerQuirkBroadcomBase::queryBufferingPercentage const): Get the buffering percentage from Queue2 if present and the player shouldn't download (streaming mode). Returns the name of the element finally used to query the percentage to, or nullptr if none was queried.
(WebCore::GStreamerQuirkBroadcomBase::correctBufferingPercentage const): On systems using PlayPump (eg: Broadcom Nexus), correct the buffering percentage with the data stored in multiqueue and PlayPump in order to make the buffering percentage more realistic. Uses the MovingAverage. Queries vidfilter and audfilter if needed, so it also works in audio or video-only pipelines.
(WebCore::GStreamerQuirkBroadcomBase::resetBufferingPercentage const): Sets the percentage to a given value in the MovingAverage.
(WebCore::GStreamerQuirkBroadcomBase::setupBufferingPercentageCorrection const): Gets/deletes references to vidfilter, multiqueue and queue2 in the quirks state.
(WebCore::GStreamerQuirkBroadcomBase::ensureState const): Retrieves GStreamerQuirkState associated to this quirk, creating one and storing it on MediaPlayerPrivateGStreamer if not already present.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcomBase.h: Added.
(WebCore::GStreamerQuirkBroadcomBase::needsBufferingPercentageCorrection const): True for this class and derived ones.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::MovingAverage): Initialize an array of "length" number of elements, asserting if length is too big that the values would create overflow when computing the average.
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::reset): Reset all the values to a given value (usually zero).
(WebCore::GStreamerQuirkBroadcomBase::MovingAverage::accumulate): Insert a new value in the array and recompute the moving average.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRealtek.h: identifier() is now const.
* Source/WebCore/platform/gstreamer/GStreamerQuirkRialto.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirkWesteros.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.cpp: Added new methods.
(WebCore::GStreamerQuirksManager::needsBufferingPercentageCorrection const): True if any configured quirk needs it. The first configured quirk that needs it will be the one responsible to fulfill all the requests for this family of methods. The other ones will be ignored, even if they also need percentage correction. This is to avoid more than one implementation doing the corrections, as we don't want them to accumulate and over-correct.
(WebCore::GStreamerQuirksManager::queryBufferingPercentage const): Forward query request to the first configured quirk needing correction.
(WebCore::GStreamerQuirksManager::correctBufferingPercentage const): Forward correction request to the first configured quirk needing correction.
(WebCore::GStreamerQuirksManager::resetBufferingPercentage const): Ditto, but for reset.
(WebCore::GStreamerQuirksManager::setupBufferingPercentageCorrection const): Ditto, but for setup.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.h:
(WebCore::GStreamerQuirkBase::GStreamerQuirkState::GStreamerQuirkState): Constructor.
(WebCore::GStreamerQuirk::needsBufferingPercentageCorrection const): Default empty implementation.
(WebCore::GStreamerQuirk::queryBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::correctBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::resetBufferingPercentage const): Ditto.
(WebCore::GStreamerQuirk::setupBufferingPercentageCorrection const): Ditto.
@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Jul 30, 2024

@eocanha Any update on the fix?
Does the above commit - eocanha/WebKit@11a45e5 has the necessary changes? If yes, I shall ignore the quirks related changes and take the rest.

@eocanha
Copy link
Member

eocanha commented Jul 30, 2024

I've been out of office the last two weeks, so the only advances have been those in the upstream commit. My two last conclusions regarding the latest problems you reported were:

  • The stuttering in CNN was "legitimate" (unstable network?). I couldn't see any strange behaviour of the buffering logic in the logs. No newly added code fixes this.
  • The Deezer problem was caused by not having into account audfilter and its PlayPump levels. I've added code (in the upstream PR) to address this.

Migrating the upstream quirks code to your branch isn't so easy, because now all the logic has been moved to the quirks code. My tasks for the next days are:

  • Migrating my latest upstream changes downstream (with quirks)
  • Migrating the downstream quirks commit to a quirk-less version for you to test
  • Debugging upstream layout test failures

@pradeep-raveendranpillai-infosys
Copy link
Author

@eocanha Any update on the quirk-less version changes?

@eocanha
Copy link
Member

eocanha commented Aug 5, 2024

Not yet. I got busy with more upstream changes asked in the latest review. 🙄

@eocanha
Copy link
Member

eocanha commented Aug 7, 2024

@pradeep-raveendranpillai-infosys I've added a new commit to the eocanha-debug-148-c-noquirks branch. That should support audio-only pipelines now and hopefully fix the Deezer issue. I can't test it myself because I don't have a test account.

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Aug 8, 2024

Thanks @eocanha.
I have started basic testing based the above changes. I found out a minor regression wrt Deezer app podcast (mp3) playback. Seek is now working but the there is a fluctuation in the current time shown just after seek. E.g. When I am at 10th second, if I seek to 40th second, the current time will be shown as 40 first and then it is shown as 11s and then it is shown 40s and is fine thereafter. I am attaching the logs here.
log.podcast.seek.timeupdate.txt

I thought I shall update you whenever I find an issue, rather than waiting for complete testing to be over, so that you can work on it immediately.

By the way this issue is not seen for video playback.

@eocanha
Copy link
Member

eocanha commented Aug 9, 2024

I would need that log, but with "webkit*:TRACE" detail level, on top of any other GST_DEBUG string affecting other elements that you might already have. I'm asking for this because this kind of log lines (which are TRACE level) are the ones that would help me to understand what's exactly happening with the currentTime/playbackPosition.

@pradeep-raveendranpillai-infosys
Copy link
Author

Changed debug level to 7 (trace) as given below.
"gstdebug":"3,GST_STATES:3,GST_PIPELINE:4,GST_EVENT:4,GST_BUS:4,webkit*:7,brcm*:5,westerosink*:5"

The log file for the play scenario with DEBUG_ONLY_ALLOW_FIRST_PLAY defined is given below
log.deezer.seek.time.issue.txt

@pradeep-raveendranpillai-infosys
Copy link
Author

@eocanha any update on the regression issue?

@eocanha
Copy link
Member

eocanha commented Aug 23, 2024

Sorry, I couldn't work on it during the last two weeks. Will retake it next week.

@eocanha
Copy link
Member

eocanha commented Aug 26, 2024

I've been analyzing the new log you submitted. playbackPosition() returns monotonically increasing positions, either live or cached. I can't see any trace of the back-and-forth position change that you describe as a regression. Filtered log lines:

0:00:16.518146051 MediaPlayerPrivateGStreamer.cpp:1601:playbackPosition:<video-player-0> Position 0:00:10.945288888, canFallBackToLastFinishedSeekPosition: false
0:00:16.518273606 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {10945288888/1000000000 = 10.945288888}
0:00:16.524589051 MediaPlayerPrivateGStreamer.cpp:536:doSeek:<video-player-0> [Buffering] Pausing pipeline, resetting buffering level to 0 and forcing m_isBuffering true before seeking on stream mode
0:00:16.525291051 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {10945288888/1000000000 = 10.945288888}
0:00:16.525686828 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {10945288888/1000000000 = 10.945288888}
0:00:16.525772125 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {10945288888/1000000000 = 10.945288888}
0:00:16.525998865 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {10945288888/1000000000 = 10.945288888}
0:00:16.535382791 MediaPlayerPrivateGStreamer.cpp:547:doSeek:<video-player-0> [Seek] Performing actual seek to 0:00:39.769777777 (endTime: 99:99:99.999999999) at rate 1.000000
0:00:16.574406791 WebKitWebSourceGStreamer.cpp:768:webKitWebSrcDoSeek:<source> Seek segment: (537991-18446744073709551615) Position previous to seek: 539735
0:00:20.890542863 MediaPlayerPrivateGStreamer.cpp:2793:updateStates:<video-player-0> [Buffering] Restarting playback (because of buffering or resuming from zero playback rate)
0:00:20.895733381 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {39.769777777}
0:00:20.895804270 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {39.769777777}
...
0:00:25.245684749 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {39795888888/1000000000 = 39.795888888}
0:00:25.245872860 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {39795888888/1000000000 = 39.795888888}
0:00:25.246095268 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {39795888888/1000000000 = 39.795888888}
0:00:25.451242786 MediaPlayerPrivateGStreamer.cpp:1601:playbackPosition:<video-player-0> Position 0:00:40.004866665, canFallBackToLastFinishedSeekPosition: false
0:00:25.451430564 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {40004866665/1000000000 = 40.004866665}
0:00:25.451534082 MediaPlayerPrivateGStreamer.cpp:1596:playbackPosition:<video-player-0> Returning cached position: {40004866665/1000000000 = 40.004866665}

@pradeep-raveendranpillai-infosys
Copy link
Author

@eocanha I think the issue may be on the app side. When I tested with Radioline app which is similar to Deezer app, the issue is not seen.
Other issue which I saw is that video playback is slow during low bandwidth network scenario. But if I enable the DEBUG_ONLY_ALLOW_FIRST_PLAY variable, the issue is not seen. I think app is calling play() during buffering in response to "canplay" event which wpe publishes when buffering is complete. You had suggested sometime back to disable app from issuing multiple play(). I wanted to ask you if its logical/possible to add that defensive check in wpe code? i.e. ignoring play/pause while buffering is happening.

Other than the above issues, I couldn't find any regression.

@eocanha
Copy link
Member

eocanha commented Aug 29, 2024

The problem with that defensive check is that it's probably going to break a lot of layout tests. My "debug hack" to disallow play/pause touches WebCore code (multiplatform code) and it can break not only WPE/WebKitGTK, but also Apple ports. I don't think such a defensive check is possible.

If you want, I can try to do the check in a private branch (like the one where I've been placing the commits all this time for you to test) and you can pick it into your downstream repository (at your own risk). Would that work for you?

@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Aug 29, 2024

By the way I was not referring to the "debug hack" which is enabled using DEBUG_ONLY_ALLOW_FIRST_PLAY. I was suggesting something like, in MediaPlayerPrivateGsteamer.cpp::play() we check if m_isBuffering is true i.e. buffering is in progress and ignore the play() request as given below:

if(m_buffering)
{
   GST_DEBUG_OBJECT(pipeline(), "Ignoring play from app while buffering");
   return;
}

I tried this change and I see that the issue is not present. Ignoring play() based on m_isBuffering seems okay to me. I would like to know your comments on this. Can this change also be taken to wpe-2.38 branch?

eocanha added a commit to eocanha/WebKit that referenced this issue Sep 6, 2024
https://bugs.webkit.org/show_bug.cgi?id=275683

Reviewed by NOBODY (OOPS!).

The usage of a fixed buffering level to evaluate the need for buffering
results in a too unstable behaviour, with quick changes between states
that may create stuttering.

This commit adds hysteresis to the buffering level, with low and high
watermark levels that trigger "buffering needed" (when below the low
watermark), "buffering completed" (when above high watermark) and "same
state as before" when the level is between both marks.

In addition to that, the pipeline is automatically paused on a seek when
working on stream mode (using GstQueue2 for partial in-memory buffering
instead of using GstDownload for full on-disk download of the media).
This is because, when seeking, rebuffering must occur from scratch to
get the data for the new target position, and buffering level starts
from 0% in that case, which means that buffering is needed and the
pipeline must be paused. Both the m_Buffering flag and
m_bufferingPercentage are immediately forced to true and 0%, respectively.
The previous values (see explanation below) are also set to the same
values by using the new resetHistory parameter in updateBufferingStatus().
This makes sure that the "end of buffering" condition can be properly
detected.

The buffering status and buffering level computation has been
centralized in updateBufferingStatus(). Both the status and the level
now store the last value, so it's possible to check if there's been any
difference on them and to decide here on the hysteresis status
evolution.

updateStates() is where the consequences of buffering changes happen.
This method now relies in the status and level updates explained in the
previous paragraph. In the specific case of an async change, the current
values for m_isBuffering and m_bufferingPercentage are ignored (previous
ones are used). This is to be able to detect significant changes in the
hysteresis (watermark level crossing) after the async change has
completed. Otherwise, we would be detecting those crossings in a moment
where nothing can be done (pipeline state changes are ignored can can't
be enforced during async state changes).

Some extra improvements have been added to adapt to the special
circumstances of Broadcom devices, where the PlayPump Nexus component
can store a lot of data which is hidden to the vanilla buffering
algorithm. Now that data is had into account to compute the realistic
buffering level. Also, more agile low/high watermarks of 20% and 80% are
used for buffering in the case of playbin2 in stream buffering mode on
Broadcom.

20-80% levels for low/high watermark are now used on all devices
(Broadcom and not Broadcom), since usage tests proved that this makes
the buffering more agile also on Raspberry Pi, for instance.

All these changes are compatible with the Quirks framework. A new
needsPlaypumpBufferingLogic() method has been added to enable the extra
buffering logic (which corrects the queue2 buffering level with the buffer
levels of PlayPump and multiqueue) on the platforms that use Nexus.

See: WebPlatformForEmbedded/WPEWebKit#1309

* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:
(WebCore::MediaPlayerPrivateGStreamer::doSeek): Pause pipeline and reset buffering level to 0% in case we're operating in stream mode.
(WebCore::MediaPlayerPrivateGStreamer::correctBufferingPercentage): On systems using PlayPump (eg: Broadcom Nexus), correct the buffering percentage with the data stored in multiqueue and PlayPump in order to make the buffering percentage more realistic.
(WebCore::MediaPlayerPrivateGStreamer::queryBufferingPercentage): Get the buffering percentage from the relevant element, by priority (queue2, audiosink, videosink, pipeline).
(WebCore::MediaPlayerPrivateGStreamer::fillTimerFired): Clarify that this method is only used in on-disk buffering. Rely on queryBufferingPercentage() now, instead of manually getting the value from here.
(WebCore::MediaPlayerPrivateGStreamer::handleMessage): Get/forget references to brcmvidfilter, multiqueue and queue2. Those will be needed by correctBufferingPercentage() later.
(WebCore::MediaPlayerPrivateGStreamer::processBufferingStats): Apply buffering percentage corrections on platforms that need them (Broadcom).
(WebCore::MediaPlayerPrivateGStreamer::updateBufferingStatus): Update the values of m_wasBuffering, m_isBuffering, m_previousBufferingPercentage, m_bufferingPercentage and m_didDownloadFinish. The first 4 attributes should *ONLY* be modified from this method, in order to guarantee coherency. The only *EXCEPTION* to this rule is the delay which can happen in updateStates(). The new resetHistory parameter sets the value both in the previous value family of attributes and in the current value family of variables.
(WebCore::MediaPlayerPrivateGStreamer::updateStates): Assume that m_wasBuffering, etc. have been precomputed by updateBufferingStatus() before updateStates() is called. In the case of an async state change, delay m_isBuffering and m_bufferingPercentage "to the past" (m_wasBuffering and m_previousBufferingPercentage), so that any change on them can be detected on the next iteration.
* Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h: Added helper MovingAverage inline class, which internally uses an array of N elements specified at construction time. Also added new m_wasBuffering and m_previousBufferingPercentage attributes to store previous values of m_isBuffering and m_bufferingPercentage and ease detection of changes. Adden new attributes to store references to vidfilter, multiqueue and queue2. Added m_streamBufferingLevelMovingAverage (configured for 10 values).
(WebCore::MediaPlayerPrivateGStreamer::MovingAverage::MovingAverage): Initialize an array of "length" number of elements.
(WebCore::MediaPlayerPrivateGStreamer::MovingAverage::~MovingAverage): Destructor.
(WebCore::MediaPlayerPrivateGStreamer::MovingAverage::reset): Reset all the values to a given value (usually zero).
(WebCore::MediaPlayerPrivateGStreamer::MovingAverage::accumulate): Insert a new value in the array and recompute the moving average.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBcmNexus.h: Override needsPlaypumpBufferingLogic(), wich is true for this platform.
* Source/WebCore/platform/gstreamer/GStreamerQuirkBroadcom.h: Ditto.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.cpp:
(WebCore::GStreamerQuirksManager::needsPlaypumpBufferingLogic const): Will be true if any of the currently configured platforms requires it.
* Source/WebCore/platform/gstreamer/GStreamerQuirks.h:
(WebCore::GStreamerQuirk::needsPlaypumpBufferingLogic const): New virtual method. Defaults to false.
@pradeep-raveendranpillai-infosys
Copy link
Author

pradeep-raveendranpillai-infosys commented Sep 11, 2024

@eocanha

  1. Can you please comment on my change made on top of your changes for ignoring multiple play requests from app during buffering?

  2. Are your other changes (quirks based) for this issue merged to wpe-2.38 main branch?

  3. Since LGI branch is pointing to wpe-2.38/Jan 15th date, I had taken the below commits from your dev branch. Please confirm if the below commits is logically equivalent to your quirks based changes.
    b8b84bd
    81fa578
    6279427
    fa843e7

@eocanha
Copy link
Member

eocanha commented Sep 12, 2024

  1. About your change, I haven't had time to check the implications in all the cases, and I'm a bit scared about unilaterally gnoring play requests causing regressions. For instance, what would happen when the video is prerolling (trying to show its first frame as a preview while still in pause because the JS code hasn't told the player that it wants to play) and buffering because of that, but right in that moment the JS code decides to play()? That play would be ignored and "lost in the void". The JS code might never issue a second play() that would put the video in movement. By now, if possible, I would have more peace of mind if you only added that code to your downstream branch, if possible.

  2. No changes are merged yet on any branch because the process is to land the patch upstream first and then backport it. I've been updating a draft version of the backports in the eocanha-debug-148-c-noquirks and eocanha-debug-148-c branches, where I add all the corrections that I do upstream through the review process. My plan is to squash all the commits of those branches and use the original upstream commit message on them when [GStreamer] Buffering hysteresis and buffering improvements for Broadcom WebKit/WebKit#29998 lands. Unfortunately, and even though I now have r+ from @calvaris as reviewer, some last minute layout test regressions have appeared and I'm working on solving them. From the 3 regressions, I've solved 2 and have only one remaining. I hope to land the patch as soon as possible, but this task has become an oddysey.

  3. On a first sight they look equivalent, yes. Did you have any merge conflict when trying to cherry-pick them?

@pradeep-raveendranpillai-infosys
Copy link
Author

  1. I shall see if the change can be limited to my downstream branch.
  2. Once you are done will all changes and backport is ready, request you to squash all the non-quirks commits and provide it in a new branch. I shall cherry pick them and after testing, will merge it to LGI's downstream branch.
  3. I had been picking and merging the changes manually on my downstream branch till now, so no.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

No branches or pull requests

3 participants