Closed Bug 1276184 Opened 5 years ago Closed 4 years ago

Assertion failure: (track[i-1]->mTrackInfo->GetID() == track[i]->mTrackInfo->GetID() && track[i-1]->mTimecode <= track[i]->mTimecode) || track[i]->mKeyframe, at TrackBuffersManager.cpp:12

Categories

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

defect

Tracking

()

RESOLVED FIXED
mozilla49
Tracking Status
firefox48 + fixed
firefox49 + fixed
firefox50 + unaffected

People

(Reporter: cbook, Assigned: jya)

References

(Blocks 1 open bug, )

Details

(Keywords: assertion)

Attachments

(8 files)

Attached file bughunter stack
Found via bughunter and reproduced on a windows 7 trunk debug build based on m-c tip

Steps to reproduce:
-> Load https://www.youtube.com/watch?v=DirSXIoL_sE
--> Assertion Failure

Assertion failure: (track[i-1]->mTrackInfo->GetID() == track[i]->mTrackInfo->GetID() && track[i-1]->mTimecode <= track[i]->mTimecode) || track[i]->mKeyframe, at c:/Users/mozilla/debug-builds/mozilla-central/dom/media/mediasource/TrackBuffersManager.cpp:1230

#01: mozilla::TrackBuffersManager::DoDemuxAudio[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3c7852a]
#02: mozilla::TrackBuffersManager::OnVideoDemuxCompleted[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3c84399]
#03: mozilla::MozPromise<RefPtr<mozilla::MediaTrackDemuxer::SamplesHolder>,enum mozilla::DemuxerFailureReason,1>::InvokeCallbackMethod<mozilla::TrackBuffersManager,void (__thiscall mozilla::TrackBuffersManager::*)(RefPtr<mozilla::MediaTrackDemuxer::SamplesHold[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3c5e51a]
#04: mozilla::MozPromise<RefPtr<mozilla::MediaTrackDemuxer::SamplesHolder>,enum mozilla::DemuxerFailureReason,1>::MethodThenValue<mozilla::TrackBuffersManager,void (__thiscall mozilla::TrackBuffersManager::*)(RefPtr<mozilla::MediaTrackDemuxer::SamplesHolder>),[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3c79ab5]
#05: mozilla::MozPromise<RefPtr<mozilla::MediaTrackDemuxer::SamplesHolder>,enum mozilla::DemuxerFailureReason,1>::ThenValueBase::DoResolveOrReject[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3a4ac03]
#06: mozilla::MozPromise<RefPtr<mozilla::MediaTrackDemuxer::SamplesHolder>,enum mozilla::DemuxerFailureReason,1>::ThenValueBase::ResolveOrRejectRunnable::Run[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x3a60536]
#07: mozilla::TaskQueue::Runner::Run[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x77d6c3]
#08: nsThreadPool::Run[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x77e5af]
#09: nsThread::ProcessNextEvent[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x777b6b]
#10: NS_ProcessNextEvent[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x7e31b2]
#11: mozilla::ipc::MessagePumpForNonMainThreads::Run[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0xff47ac]
#12: MessageLoop::RunInternal[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0xf9291d]
#13: MessageLoop::RunHandler[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0xf92892]
#14: MessageLoop::Run[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0xf9248d]
#15: nsThread::ThreadFunc[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\xul.dll +0x782b33]
#16: _PR_NativeRunThread[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\nss3.dll +0x2fb02b]
#17: _PR_MD_YIELD[c:\Users\mozilla\debug-builds\mozilla-central\firefox-debug\dist\bin\nss3.dll +0x2e01f9]
#18: crt_at_quick_exit[C:\Windows\system32\ucrtbase.DLL +0x7f794]
#19: BaseThreadInitThunk[C:\Windows\system32\kernel32.dll +0x4ef1c]
#20: RtlInitializeExceptionChain[C:\Windows\SYSTEM32\ntdll.dll +0x63648]
Assignee: nobody → jyavenard
Blocks: MSE
jean-yves also tested on beta with a build based on https://hg.mozilla.org/releases/mozilla-beta/rev/2ee4473c729acb2ba7dc723e7affe79ce14bff85 and also shows this assertion. So i can confirm its a regression
Flags: needinfo?(jyavenard)
Thanks.. Any chances you can see if it reproduces in 46?
Flags: needinfo?(jyavenard)
found a 46 tinderbox debug build based on https://hg.mozilla.org/releases/mozilla-beta/rev/f51382b3b967a684813ed6f6aa4be0aaab766d6f

and in 46 the assertion is 

Assertion failure: (track[i-1]->mTrackInfo->GetID() == track[i]->mTrackInfo->GetID() && track[i-1]->mTimecode <= track[i]->mTimecode) || track[i]->mKeyframe, at c:/builds/moz2_slave/m-beta-w32-d-00000000000000000/build/src/dom/media/mediasource/TrackBuffersManager.cpp:1224
#01: JS::ubi::DominatorTree::root[xul +0x188062e]
#02: JS::ubi::DominatorTree::root[xul +0x1886e59]
#03: JS::ubi::DominatorTree::root[xul +0x187564d]
#04: JS::ubi::DominatorTree::root[xul +0x1881266]
#05: JS::ubi::DominatorTree::root[xul +0x1795504]
#06: JS::ubi::DominatorTree::root[xul +0x179d457]
#07: XRE_AddStaticComponent[xul +0x113b34]
#08: XRE_AddStaticComponent[xul +0x114413]
#09: XRE_AddStaticComponent[xul +0x1114ce]
#10: NS_StringSetIsVoid[xul +0x13ee6b]
#11: mozilla::SandboxTarget::Instance[xul +0x407be1]
#12: mozilla::LoadInfo::TriggeringPrincipal[xul +0x3d6712]
#13: mozilla::LoadInfo::TriggeringPrincipal[xul +0x3d66ca]
#14: mozilla::LoadInfo::TriggeringPrincipal[xul +0x3d6443]
#15: XRE_AddStaticComponent[xul +0x1168e4]
#16: PR_NativeCreateThread[nss3 +0x207698]
#17: PR_MD_WAIT_CV[nss3 +0x1f82ef]
#18: _get_flsindex[MSVCR120 +0x2c01d]
#19: _get_flsindex[MSVCR120 +0x2c001]
#20: BaseThreadInitThunk[kernel32 +0x4ef1c]
#21: RtlInitializeExceptionChain[ntdll +0x63648]
#22: RtlInitializeExceptionChain[ntdll +0x6361b]
Can't reproduce it :(

Tried with mp4 MSE and webm (this video only has a webm/vorbis stream) ; at every resolutions available. I never hit this assert :(

Carsten, can you reproduce doing the following?

Pause the video
Seek to 0
In the settings -> Quality, go through each available resolution (144, 240, 360, 480, 720, 1080p). When changing resolution let it buffer to the end

Does it crash?

Can you manually reproduce it? when you right click on the playback window and select "stats for nerds" what does it show (hoping this would be available prior the assert)

Side note, that bird look like an australian tawny frogmouth, though I've never heard those make any noise.
Flags: needinfo?(cbook)
and what's the result of youtube.com/html5 ?
Component: Audio/Video → Audio/Video: Playback
Attached file youtube debug info
Flags: needinfo?(cbook)
can still reproduce the crash. Seems this crash only at this special resolution and somehow i was also not able to crash with mozregression. 

So this win7 debug build based on m-c shows the assertion but it seems builds like from mozregression not.
Attached image youtube/html5
jya: tried your debug patch and does not crash anymore :( but i still keep trying, maybe this is something that happen only like on europe's mornings or so :(
Attached file mediasource.zip
media source files when the crash happened
It seems this crash depend a lot on your connection speed - 
high speed internet connection -> no crash
slower internet connection (and so the resolution changes) or a connection that use several things like streams etc at once -> assertion

i was not able to reproduce in a normal environment anymore (using the 1280 x 720 resolution) but using a tool in the vm that force-reduce my connection speed worked to reproduce (had to load other tabs and webradio also to produce some load).
The error occurs because the last sample of a packet has the same start time at the sample of the next packet:
[MediaPlayback #3]: D/MediaSourceSamples TrackBuffersManager(1343ed000:video/webm)::ProcessFrames: Processing video/webm; codecs=vp9 frame(pts:25025000 end:25092000, dts:25025000, duration:67000, kf:0)

[MediaPlayback #3]: D/MediaSourceSamples TrackBuffersManager(1343ed000:video/webm)::ProcessFrames: Processing video/webm; codecs=vp9 frame(pts:25025000 end:25092000, dts:25025000, duration:67000, kf:1)

for some reason that duplicate frame isn't removed when it should be.

While playing this file, I found a few times that the playback would jump straight at the end even though we were continuously adding data; it should have stopped and waited for more data to be added. But for some reasons it didn't.
This is likely what is causing some error such as:
28 INFO TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_DrainOnMissingData_mp4.html | Video has correct currentTime. - got 9.977, expected 0.801666
https://treeherder.mozilla.org/logviewer.html#?job_id=29270782&repo=mozilla-inbound
We keep the next position on where to add frames so that we do not break the current coded frame group. However, when the new group of added frames starts with a keyframe we do not have to worry about breaking the previous coded frame group.

Review commit: https://reviewboard.mozilla.org/r/57144/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/57144/
Attachment #8759056 - Flags: review?(dglastonbury)
Attachment #8759057 - Flags: review?(dglastonbury)
Attachment #8759058 - Flags: review?(dglastonbury)
The index at which we are removing frames is always the one where we will be inserting the next ones.

Review commit: https://reviewboard.mozilla.org/r/57146/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/57146/
See Also: → 1277733
Comment on attachment 8759056 [details]
MozReview Request: Bug 1276184: [MSE] P1. Scan where to start removing frames from the start if new block added starts with a keyframe. r?kamidphish

https://reviewboard.mozilla.org/r/57144/#review54234
Attachment #8759056 - Flags: review?(dglastonbury) → review+
Comment on attachment 8759057 [details]
MozReview Request: Bug 1276184: [MSE] P2. Remove the need to scan the track buffer when frames are being removed. r?kamidphish

https://reviewboard.mozilla.org/r/57146/#review54236
Attachment #8759057 - Flags: review?(dglastonbury) → review+
Comment on attachment 8759058 [details]
MozReview Request: Bug 1276184: [MSE] P3. Be consistent with types when accessing track buffer. r?kamidphish

https://reviewboard.mozilla.org/r/57148/#review54240
Attachment #8759058 - Flags: review?(dglastonbury) → review+
Pushed by jyavenard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/fa6a1c27983f
[MSE] P1. Scan where to start removing frames from the start if new block added starts with a keyframe. r=kamidphish
https://hg.mozilla.org/integration/mozilla-inbound/rev/0567d1267d23
[MSE] P2. Remove the need to scan the track buffer when frames are being removed. r=kamidphish
https://hg.mozilla.org/integration/mozilla-inbound/rev/71a44348d3b7
[MSE] P3. Be consistent with types when accessing track buffer. r=kamidphish
https://hg.mozilla.org/mozilla-central/rev/fa6a1c27983f
https://hg.mozilla.org/mozilla-central/rev/0567d1267d23
https://hg.mozilla.org/mozilla-central/rev/71a44348d3b7
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla49
Comment on attachment 8759056 [details]
MozReview Request: Bug 1276184: [MSE] P1. Scan where to start removing frames from the start if new block added starts with a keyframe. r?kamidphish

Approval Request Comment
[Feature/regressing bug #]: MSE
[User impact if declined]: Potential stalls with some YouTube videos
[Describe test coverage new/current, TreeHerder]: In central for a few weeks.
[Risks and why]: Low. Special case for some of the webm youtube videos. Not the best fix, but will do for now. 
[String/UUID change made/needed]: None
Attachment #8759056 - Flags: approval-mozilla-beta?
Attachment #8759056 - Flags: approval-mozilla-aurora?
I guess this uplift is for the three patches?
Flags: needinfo?(jyavenard)
Dan, can you answer since jya is on PTO? Also I'm hoping you can be around if we end up having to back this out or if there are problems.
Flags: needinfo?(dglastonbury)
Comment on attachment 8759056 [details]
MozReview Request: Bug 1276184: [MSE] P1. Scan where to start removing frames from the start if new block added starts with a keyframe. r?kamidphish

Let's try this in aurora, all 3 patches.

Since this isn't fixing a known reported issue maybe it would be best to keep this change on aurora without uplifting further.
Attachment #8759056 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
(In reply to Liz Henry (:lizzard) (needinfo? me) from comment #24)
> Dan, can you answer since jya is on PTO? Also I'm hoping you can be around
> if we end up having to back this out or if there are problems.

Yes, uplift needs to be three patches. I'll be around.
Flags: needinfo?(dglastonbury)
Comment on attachment 8759056 [details]
MozReview Request: Bug 1276184: [MSE] P1. Scan where to start removing frames from the start if new block added starts with a keyframe. r?kamidphish

It's a possible fix. Let's take it in 48 beta 6 and keep monitoring the result.
Attachment #8759056 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Tracking this and see if any regressions happen.
(In reply to Liz Henry (:lizzard) (needinfo? me) from comment #25)
> Comment on attachment 8759056 [details]
> MozReview Request: Bug 1276184: [MSE] P1. Scan where to start removing
> frames from the start if new block added starts with a keyframe. r?kamidphish
> 
> Let's try this in aurora, all 3 patches.
> 
> Since this isn't fixing a known reported issue maybe it would be best to
> keep this change on aurora without uplifting further.

its already on aurora with the mergeday in june
Flags: needinfo?(jyavenard)
Depends on: 1285987
No longer depends on: 1285987
Depends on: 1285987
You need to log in before you can comment on or make changes to this bug.