in YT dash tests suite, test #87 failed because of "Assert failed: Source buffer number is (3) which should be (1)" |
||||||||
Issue descriptionVersion: Chrome 55 OS: All The test #87 failed because of error: "Assert failed: Source buffer number is (3) which should be (1)" Thom, this test fail in all OS. can you take a look? if it's code bug, please assign to wolen What steps will reproduce the problem? (1) navigate to http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/tip.html?test_type=conformance-test×tamp=1473977902647 (2) click test #87 What is the expected output? test pass What do you see instead? test fail because of "Assert failed: Source buffer number is (3) which should be (1)"
,
Sep 15 2016
,
Sep 15 2016
,
Sep 15 2016
,
Sep 16 2016
I repro'ed this on a ToT build.
Debug logs show the following coded frame append sequence (just 1 video track):
Append VIDEO: buffers dts=[5.005;5.67238] pts=[5.005;5.63067(last frame dur=0.041711)] <--- only the first frame in DTS sequence is a keyframe here.
Append VIDEO: done. ranges_=[5.005;5.67238(5.71409)]
--
Append VIDEO: buffers dts=[5.71409;6.42318] pts=[5.7558;6.38147(last frame dur=0.041711)] <--- no keyframes
Append VIDEO: done. ranges_=[5.005;6.42318(6.46489)]
--
Append VIDEO: buffers dts=[6.46489;7.34082] pts=[6.50659;7.29911(last frame dur=0.041711)] <--- no keyframes
Append VIDEO: done. ranges_=[5.005;7.34082(7.38253)]
--
Append VIDEO: buffers dts=[7.38253;8.50873] pts=[7.42424;8.46702(last frame dur=0.041711)] <--- no keyframes
Append VIDEO: done. ranges_=[5.005;8.50873(8.55044)]
--
Append VIDEO: buffers dts=[8.55044;9.63493] pts=[8.59215;9.67663(last frame dur=0.041711)] <--- no keyframes
Append VIDEO: done. ranges_=[5.005;9.63493(9.67664)]
--
Append VIDEO: buffers dts=[9.67664;9.96862] pts=[9.63493;9.96861(last frame dur=0.041711)] <--- no keyframes
Append VIDEO: done. ranges_=[5.005;9.96862(10.0103)]
--
appendBufferAsyncPart done. this=....buffered="{ [5.005;10.0103] }"
TestExecutor: checkEq passed: Source buffer number is (1).
--
Append VIDEO: buffers dts/pts=[0;1.5016(last frame dur=0.041711)] (begins with a keyframe)
Append VIDEO: done. ranges_=[0;1.5016(1.54331)] [5.005;9.96862(10.0103)]
--
.... more appends....
--
Append VIDEO: buffers dts=[4.71335;4.96362] pts=[4.75507;4.92191(last frame dur=0.041711)]
RemoveInternal VIDEO: before remove ranges_=[0;4.67164(4.71335)] [5.005;9.96862(10.0103)]
RemoveInternal VIDEO (4.71335, 5.00533, 0)
RemoveInternal VIDEO: after remove ranges_=[0;4.67164(4.71335)]
Append VIDEO: done. ranges_=[0;4.96362(5.00533)]
--
I stopped inspecting the log here because it looks like the problem is two, or perhaps three-fold and likely results in the eventual discontinuous set of 3 buffered ranges if this behavior continues:
1) Chrome is incorrectly using DTS, not PTS to report buffered ranges (known issues)
Due to this:
2) The start time of the first appended media segment is 5.005s, but the end time of the second appended media segment is 5.005311. This triggers removal of the first portion of the first appended media segment (which is the *only* keyframe in that first appended media segment, so *all* of its dependent frames (all of that first appended media segment) are also removed.
3) As an aside: how was this mp4 muxed? There are frequently frames with DTS > PTS, and this doesn't make sense to me. (For example: "ProcessFrame: WARNING: Frame DTS(4.62993) > PTS(4.58822), frame type=video")
---
Now let's see what might happen if Chrome did the buffered ranges and removes based on PTS, not DTS:
First media segment would be PTS: [5.005, 9.96861+0.041711) = [5.005, 10.010321)
Second media segment would be PTS: [0, 4.96361+0.041711 **) = [0, 5.005321)
** This PTS is the highest in the media segment, but isn't the last due to out-of-order sequence of PTS vs DTS.
Importantly, note that even if Chrome *did not incorrectly conflate PTS and DTS for buffered range and removals*, the first appended media segment begins before the second appended media segment ends, so the same thing would occur: all of the first appended media segment would be removed due to the second appended media segment overlapping the beginning (the sole keyframe) of the first appended media segment.
As such, this looks like a test issue with the h264 media. Back to tdedecko@.
** tdedecko@: please change back to untriaged if you the h264 media is actually correct **
FYI the bugs tracking getting Chrome to do the right thing for MSE w.r.t. ISOBMFF out-of-order and distinct PTS vs DTS are https://bugs.chromium.org/p/chromium/issues/list?can=2&q=owner%3Ame+label%3AMSEptsdtscleanup&colspec=ID+Pri+M+Stars+ReleaseBlock+Component+Status+Owner+Summary+OS+Modified&x=m&y=releaseblock&cells=ids
,
Sep 16 2016
Hmm. I'm rereading the MSE coded frame processing algorithm spec around this and I need to look more deeply into the following log entries' implementation: RemoveInternal VIDEO (4.71335, 5.00533, 0)
,
Sep 16 2016
wrt #6, I looked more deeply and that RemoveInternal is correct. Related spec text: "If highest end timestamp for track buffer is set and less than or equal to presentation timestamp: Remove all coded frames from track buffer that have a presentation timestamp greater than or equal to highest end timestamp and less than frame end timestamp" I'm not sure how I misread that yesterday, but I was briefly really concerned the spec had a big gap in logic there. It doesn't. So, back to tdedecko@, since this looks like a legitimate result of overlapped append removing a previously appended keyframe (and all of its dependencies), and thereby introducing a buffered range gap. The overlap is tiny, and I suspect the real problem is the test media segments overlap each other slightly in the timeline. If appended in timeline sequence, there would be no problem (the keyframes would overlap, not be overlapped). But the out of order append demonstrates the overlap can have consequences in a compliant MSE coded frame processing implementation. Thankfully, this issue is not resulting from the known PTS vs DTS conflation (as demonstrated in log analysis in #5), since then it would be harder to show that the test media is the problem.
,
Sep 16 2016
Thanks Matt for the helpful investigation and analysis. I'll replace the media for this test.
,
Sep 22 2016
Just put in the fix for this. The change should go out at 2pm today.
,
Sep 23 2016
tdedecko@, can you describe the fix please? Was it remuxing the test media so there was no overlap between segments?
,
Sep 26 2016
I didn't explicitly remux the content. The test media was an old encode from viper. I pulled down a recent encode from viper which did not have the overlapping segments. I'm explicitly using that newer encode just for that test.
,
Sep 26 2016
@#11: Sounds good. Do any of the "old encodes" still exist in YT production, along with out-of-order append behavior which could cause these gaps and stalls?
,
Sep 28 2016
This shouldn't be an issue on the YT side since the player re-writes timestamps when they are overlapping.
,
Sep 28 2016
@#13 Thanks for checking that. SGTM. |
||||||||
►
Sign in to add a comment |
||||||||
Comment 1 by tdedecko@google.com
, Sep 15 2016