1909543 - Assertion `MOZ_ASSERT(aTrackData.mBufferedRanges.IsEmpty())` while watching Ads on Netflix

Status: NEW

(Core :: Audio/Video: Playback, defect, P1)

Description

[Alastor Wu [:alwu]]

Attachment: Log

This assertion was hit while watching Ads on Netflix.

D/MediaSource TrackBuffersManager[2d91e2edb00] ::RemoveFrames: Removing [(1141.555667, 1152.597292), (1152.597292, 1186.388667)] from bufferedRange [(1141.555667, 1186.388667)]

This removal range should be combined to one, not two separate ranges. This incorrect removal range causes wrong buffered range.

D/MediaSource TrackBuffersManager[2d91e2edb00] ::RemoveFrames: After removing frames, video/avc data sz=0, highestStartTimestamp= 0, bufferedRange=[(1152.597292, 1152.597292)], sanitizedBufferedRanges=[(1152.597292, 1152.597292)]

Comment 1

[Alastor Wu [:alwu]]

Attachment: Bug 1909543 - set fuzz on removed interval to keep the buffered range correct after removal.

Comment 2

[Karl Tomlinson (:karlt)]

Interesting!

CodedFrameRemoval: before video ranges=[({11415556670,10000000}, {11863886670,10000000})]

The base indicates that the numerator represents tenths of microseconds, but it looks to be rounded to microseconds here.

The difference in rounding between the 1152597291 from ToMicroseconds(), which rounds toward zero, and 1152.597292 from ToSeconds(), which rounds to nearest, implies that not all timestamps are rounded to microseconds.

TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152555667,1152597291] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152472333,1152514000] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152514000,1152555667] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152597291,1152638958] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152763958,1152805625] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152680625,1152722291] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152638958,1152680625] with [0,1186388667] dropping
TrackBuffersManager[2d91e2edb00] ::RemoveFrames: overriding start of frame [1152722291,1152763958] with [0,1186388667] dropping

The frame at 1152555667 has 41624 microsecond duration. The surrounding frames are either 41666 or 41667, as expected for 24 fps.

Perhaps the glitch might be due to the timestampOffset attribute, but that is rounded to microseconds, so the non-zero tenths of microseconds are not from that.

Comment 3

[Karl Tomlinson (:karlt)]

(In reply to Alastor Wu [:alwu] from comment #0)

This assertion was hit while watching Ads on Netflix.

D/MediaSource TrackBuffersManager[2d91e2edb00] ::RemoveFrames: Removing [(1141.555667, 1152.597292), (1152.597292, 1186.388667)] from bufferedRange [(1141.555667, 1186.388667)]

This removal range should be combined to one, not two separate ranges.

Perhaps. It would be interesting to know why it is not combined.
The first 1152.597292 comes from start time + duration arithmetic. This could be inaccurate if the denominators differ, perhaps due duration truncation on frame insertion or elsewhere.

This incorrect removal range causes wrong buffered range.

D/MediaSource TrackBuffersManager[2d91e2edb00] ::RemoveFrames: After removing frames, video/avc data sz=0, highestStartTimestamp= 0, bufferedRange=[(1152.597292, 1152.597292)], sanitizedBufferedRanges=[(1152.597292, 1152.597292)]

Apparently either

1. we have bugs in our intervals arithmetic (e.g. bug 1909614),
2. the removal range does not accurately represent the frames removed,
3. mBufferedRanges did not accurately represent the frames before removal (e.g. bug 1909750),
4. or some combination of these.