[wpe-2.38] MP4 edit lists support breaks smooth playback

[volodymyr-ogorodnik-red]

One more scenario found where MP4 edit-list support (#1185) breaks smooth playback ( real customer impacted).
Scenario is originated from Ads insertion into streaming playback, but in general such circumstances could appear on any segmented streams that uses adaptive bitrate playback and mixes content without buffers flush.

Let assume stream A (main video) has edit list with start=0:00:00.083416750.
And stream B (short Ad) has edit list with start=0:00:00.041711111

Now we play Stream A for 15 mins, next Stream B for 30 secs and continue Stream A starting from 15th minute

Also player uses timestampOffset to align pieces in timeline.
for stream B: m_timestampOffset={"value":1066.856901}
in for second part stream A: m_timestampOffset={"value":195.9440000990993}

So last frame from Stream B goes with these numbers:
original values from qtdemux in AppSinkFlushCapsWorkaroundProbe::probe(): buffer: 0x233f540, pts 0:00:29.988355555, dts 0:00:29.946644444, dur 0:00:00.041711111, size 999, offset none, offset_end none, flags 0x6000

original sample on entry in SourceBufferPrivate::didReceiveSample() (adjusted by segment start=0:00:00.041711111):
{"size":999,"pts":{"value":29.946644444,"numerator":29946644444,"denominator":1000000000,"flags":1},"dts":{"value":29.904933333,"numerator":29904933333,"denominator":1000000000,"flags":1},

and updated sample adjusted by m_timestampOffset={"value":1066.856901} :
{"size":999,"pts":{"value":1096.803545444,"numerator":1096803545444,"denominator":1000000000,"flags":1},"dts":{"value":1096.761834333,"numerator":1096761834333,"denominator":1000000000,"flags":1},

The first sample from stream A at 15min looks like:
original values from qtdemux in AppSinkFlushCapsWorkaroundProbe::probe(): buffer: 0x1fe7540, pts 0:15:00.984317650, dts 0:15:00.900900900, dur 0:00:00.041708375, size 1282, offset none, offset_end none, flags 0x4040)

original sample on entry in SourceBufferPrivate::didReceiveSample() (adjusted by segment start=0:00:00.083416750):
{"size":1282,"pts":{"value":900.9009009,"numerator":900900900900,"denominator":1000000000,"flags":1},"dts":{"value":900.81748415,"numerator":900817484150,"denominator":1000000000,"flags":1},

and updated sample adjusted by m_timestampOffset={"value":195.9440000990993}
{"size":1282,"pts":{"value":1096.844900999,"numerator":1096844900999,"denominator":1000000000,"flags":1},"dts":{"value":1096.761484249,"numerator":1096761484249,"denominator":1000000000,"flags":1}

Next two bad things happen in didReceiveSample():

• removing last frame from stream B (in fact it is already passed downstream and will be decoded/displayed):
  SourceBufferPrivateGStreamer::didReceiveSample(5D620002) Discovered out-of-order frames, from: {"size":999,"pts":{"value":1096.803545444,"numerator":1096803545444,"denominator":1000000000,"flags":1},"dts":{"value":1096.761834333,"numerator":1096761834333,"denominator":1000000000,"flags":1},
  Jul 15 13:42:54.969223 E0B7B1-APPSTB-301000193203 WPEWebProcess[28120]: 250715-12:42:54.969114 [mod=Media, lvl=DEBUG] [tid=18] TrackBuffer::didReceiveSample(5D621B75) removing sample {"size":999,"pts":{"value":1096.803545444,"numerator":1096803545444,"denominator":1000000000,"flags":1},"dts":{"value":1096.761834333,"numerator":1096761834333,"denominator":1000000000,"flags":1},

• not inserting first frame from stream A (really, really bad if this is an I-Frame), extra debug shows this:
  SourceBufferPrivateGStreamer::didReceiveSample(5D620002) skip unordered sample, lastEnqueuedDecodeKey: dts:{"value":1096.761834333,"numerator":1096761834333,"denominator":1000000000,"flags":1} pts:{"value":1096.803545444,"numerator":1096803545444,"denominator":1000000000,"flags":1}

When I have removed edit list support, all PTSes/DTSes are aligned and no frame is lost:
Stream B has last inserted frame: pts: 1096,845256555, dts: 1096,80354544
Stream A has first inserted frame: pts: 1096,928317749 dts: 1096,844900999

It is also not a perfect state, since last frame from stream B will have extended presentation duration, but this is rather pure player issue.

Some ideas went trough my mind while analyzing this situation (all have drawbacks, unfortunately):

• adjust timestampOffset with offsets from edit-list
• adjust/keep in sync lastEnqueuedDecodeKey when we have removed samples from buffer
• keep/remove all frames staring from "random-access points" to avoid macroblocks/artefacts when decoding

I can provide more logs/details related to my case if needed.
Any proposal to try besides reverting edit-list support is much appreciated.

Thank you.
Vova.

[eocanha]

Thanks for the very detailed description of the problem. It's very useful to understand the nature of the problem and try to solve it. This issue might be connected with the problems detected upstream when the last edit list patch was reintroduced (https://bugs.webkit.org/show_bug.cgi?id=231019), and which forced the reversion of the patch there (in https://bugs.webkit.org/show_bug.cgi?id=244428). As YouTube TV support is now provided by Cobalt, I thought that edit list support downstream wouldn't cause problems, but this Issue proves that the problems are actually there.

I'll try to prioritize this issue but, as everything involving this kind of things, it's not something that can be solved in a short timespan (days). Reverting the edit lists patch downstream isn't an option either, as that would break other things.

[eocanha]

Some thoughts:

It would be really helpful to have a minimal reproduction test case that doesn't depend on playing a video in the wild on a JS video player influenced by physical time and other factors.

With such a test case, we could compare the behaviour in WPE and in other browsers such as Chromium or Firefox, to try to see who's wrong. With the current information we can't know if the original webpage is properly deciding to apply the right timestampOffset, or if videos with the right timestamps are supplied.

[volodymyr-ogorodnik-red]

The original issue we have seen on Paramount+ player with enabled ads insertion. Some specific app configuration/version, account, and other limitations won't help in verification, thus I am looking for static test streams that could show the issue. Maybe artificial but simple enough to compare between platforms.

[eocanha]

I'm trying to work on creating a test case with edit lists having the very same offsets as the ones you mentioned, to try to "sort of" reproduce your same conditions. When I get that, I'll compare what the different browsers do to try to understand what happens.

[eocanha]

Managed to create a test case. Not exactly with the same conditions (so it still needs more work), but at least now I know how to create arbitrary empty edit lists from an unedited file:

MP4Box -frag 10000 -out ibpibp-frag-edits.mp4 -delay 1=-1/3 ibpibp-frag-template.mp4

Where MP4Box is a tool that comes in the gpac package in Ubuntu, and ibpibp-frag-template.mp4 comes from here.

While doing this, I realized that our buildroot wpe branch (the one we use for development) is applying this patch for wpe-2.38 (but not to wpe-2.46!!, that's a different problem we have to solve if we want PR #1536 to work properly) to make qtdemux properly honor edit lists on MSE (push based scheduling).

Please, @volodymyr-ogorodnik-red, could you make sure that the qtdemux patch is being applied in your setup? Otherwise, it's "expected" that edit lists don't work.

In the meantime, I keep debugging the test case I created here to see if I find anything wrong.

[volodymyr-ogorodnik-red]

currently we use gstreamer 1.18.5 and qtdemux code looks like:

  /* push based does not handle segments, so act accordingly here,
   * and warn if applicable */
  if (!qtdemux->pullbased && !allow_pushbased_edts) {
    GST_WARNING_OBJECT (qtdemux, "streaming; discarding edit list segments");
    /* remove and use default one below, we stream like it anyway */
    g_free (stream->segments);
    stream->segments = NULL;
    stream->n_segments = 0;
  }

Please confirm this is the "right" condition.

[eocanha]

Yes, it's the right condition. If you can confirm that there aren't any "streaming; discarding edit list segments" messages in the logs when adding qtdemux:WARN (or a more detailed level) to GST_DEBUG, then that would confirm for sure that edit lists are being applied. Also, messages like these (but with different timestamps, of course) should appear:

0:00:01.413316457   452  0x1d9a720 TRACE              webkitmse Source/WebCore/platform/graphics/gstreamer/mse/AppendPipeline.cpp:476:appsinkNewSample:<webkitappsinkwithworkarounds1:sink> Mapped buffer to segment, PTS 0:00:00.333333333 -> {0/1000000000 = 0} DTS 0:00:00.000000000 -> {-333333333/1000000000 = -0.333333333}
0:00:01.413408176   452  0x1d9a720 TRACE              webkitmse Source/WebCore/platform/graphics/gstreamer/mse/AppendPipeline.cpp:489:appsinkNewSample:<append-pipeline-video-mp4-0> append: trackId=V0 PTS={0/1000000000 = 0} DTS={-333333333/1000000000 = -0.333333333} DUR={333333/1000000 = 0.333333} presentationSize=320x240

(In this example, an edit list of -0.333333 is being applied)

Now one question:

So last frame from Stream B goes with these numbers:
original values from qtdemux in AppSinkFlushCapsWorkaroundProbe::probe(): buffer: 0x233f540, pts 0:00:29.988355555, dts 0:00:29.946644444, dur 0:00:00.041711111, size 999, offset none, offset_end none, flags 0x6000

original sample on entry in SourceBufferPrivate::didReceiveSample() (adjusted by segment start=0:00:00.041711111):
{"size":999,"pts":{"value":29.946644444,"numerator":29946644444,"denominator":1000000000,"flags":1},"dts":{"value":29.904933333,"numerator":29904933333,"denominator":1000000000,"flags":1},

Where is that "adjusted by segment start" comment coming from? The append pipeline should already be performing the adjustment (see "Mapped buffer to segment" line in my log). Is that what your comment means?

Finally, it would be nice to have the full log if possible, so that I can see everything in context. At least I would need export GST_DEBUG="*:WARN,webkit*:TRACE,qtdemux:TRACE" to see interesting stuff.

[volodymyr-ogorodnik-red]

"adjusted by segment start" is just my comment to pay attention to the pts/dts values difference comparing to original values. They were printed at the very beginning SourceBufferPrivate::didReceiveSample(). I have added several dumps in my code for better understanding the flow and where the timestamps changed.

Here is the full log with trace level debugs (and without my extra changes).

log_wpe_trace.log.gz

User scenario is: start playback, watch inserted Ads(90sec), watch stream, watch partial Ads(1-2sec), watch stream

Two moments captured when we loose data and see glitches/macroblocks on screen:

• when first Ads segment ends:
  Aug 06 12:10:51.207264 E0B7B1-APPSTB-301000193203 WPEWebProcess[3923]: 250806-11:10:51.207183 [mod=MediaSource, lvl=INFO] [tid=27] SourceBufferPrivateGStreamer::didReceiveSample(8BE50002) Discovered out-of-order frames, from: {"pts":{"value":378.168926444,"numerator":378168926444,"denominator":1000000000,"flags":1},"dts":{"value":378.168926444,"numerator":378168926444,"denominator":1000000000,"flags":1},"duration":{"value":0.041711,"numerator":41711,"denominator":1000000,"flags":1},"flags":0,"presentationSize":{"width":1920,"height":1080}} to: [end]

• when second Ads segment ends:
  Aug 06 12:11:50.136195 E0B7B1-APPSTB-301000193203 WPEWebProcess[3923]: 250806-11:11:50.136152 [mod=MediaSource, lvl=INFO] [tid=27] SourceBufferPrivateGStreamer::didReceiveSample(8BE50002) Discovered out-of-order frames, from: {"pts":{"value":1086.751834333,"numerator":1086751834333,"denominator":1000000000,"flags":1},"dts":{"value":1086.751834333,"numerator":1086751834333,"denominator":1000000000,"flags":1},"duration":{"value":0.041711,"numerator":41711,"denominator":1000000,"flags":1},"flags":0,"presentationSize":{"width":1280,"height":720}} to: [end]

[eocanha]

After examining the logs, I'm starting to think that this might be a problem with the JavaScript web player. The edit lists (specifically empty edits, that is, edit lists that just "offset the movie one frame earlier into the futue" (so future frames happen earlier)) are there for a reason (move all the PTSs one frame earlier).

It looks to me that the JavaScript code deciding what m_timeOffset to apply isn't having into account the edit lists and it's the one causing the issues (deciding the wrong offset). Maybe the webapp is adapted for a browser that doesn't support edit lists (strange, since Chrome supports it), and it now failing with WPE, which supports them. Probably, even the browser the webapp is adapted for is even a former version of WPE and the app needs to be updated.

The right way to see if it's the app or WPE the one who's wrong would be to try to run the app in another browser (ideally Chrome) and see if the continuation of the movie after the ads triggers the same frame overlap that triggers cascade deletions and causes macroblocks. In that case, the webapp is the one that needs to correct the way it computes m_timestampOffset, not WPE and WPE can't correct it on its own (otherwise it would be defeating the edit lists purpose and breaking all the other websites that do need edit lists to work).

Would it be possible to check the behaviour in Chrome and to change the webapp if the problem also happens there?

In parallel, I'm going to keep debugging some Web Platform Tests that are failing upstream when edit lists are enabled. Maybe that WPT repeatable test case can be easier to debug than this "opportunistic (not 100% repeatable)" test case.

[volodymyr-ogorodnik-red]

We have started the issue analyzis because ' vendor claims this only happens on our STBs. '
That does not mean the exactly same player is used for other devices/platforms.
So I have asked to test the same player on Chrome and check the results (assuming it is possible).

On the other hand - I'm not sure that browser is able somehow notify player, that it has 'shifted' piece of stream internally by edit-list. We adjust samples, not segments. Is there anything player can use to react on edit-lists (segment start, offset values, something else)?

[eocanha]

Is there anything player can use to react on edit-lists (segment start, offset values, something else)?

No, edit lists are internal to the media data, so they're transparent for the JavaScript code in the webpage. But now that you mention Segments, there's something important here that I've used to back my last explanation up:

The generated samples (minus timestampOffset, I wish we could debug all this without timestampOffsets because they just make the analysis more complex) should adhere to the segment limits. I mean, if the JS player (because of the adaptive streaming video manifest that it pre-processes to know what segment to append) is expecting a segment with some range (eg: [10, 15] sec.) and the samples (after applying edit lists) don't start or end in the expected range, that's a problem. The edit lists aren't meant to produce samples starting from (let's say) 9.6666 sec (assuming a duration of 0.3333 and an edit list that offsets the PTS -0.3333). They're expected to have an internal first PTS of 0.3333 that will be "corrected" by the edit list to 0.0000, and therefore comply with the expected segment timestamp range.

If the generated samples don't comply with the range, the problem may be in our append processing, or it may be because the segments were originally badly indexed on server side. But the edit lists are there to help (to correct the PTSs), not to screw things up.

Do we have any way to know what the segment limits are? Ideally we could try to process (append, or send through a player/analyzer) a whole segment and check that the generated timestamps adhere to it.