1357040 - Crash in mozilla::MP4Demuxer::NotifyDataArrived

Status: RESOLVED FIXED

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

Description

[Marcia Knous [:marcia]]

This bug was filed from the Socorro interface and is 
report bp-631c3f32-056d-4d31-a121-d40c92170417.
=============================================================

Seen while looking at nightly crash stats - earliest crashes seem to be in 20170331030216: http://bit.ly/2ppvgx2. Crashes affect Win, Linux and Android on nightly but the majority affect Linux. This crash is also present on Aurora.

ni on :gerald since it appears he worked in this area of code and might have some ideas.

Comment 1

[Bob Clary [:bc] (inactive)]

Bughunter can reproduce this on an NSFW url on Linux. It appears to be a null ptr access. Crashes opt and asserts in debug Nightly.

Assertion failure: mRawPtr != nullptr (You can't dereference a NULL RefPtr with operator->().), at /home/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RefPtr.h:315
#01: mozilla::MP4Demuxer::NotifyDataArrived [dom/media/fmp4/MP4Demuxer.cpp:624]
#02: mozilla::detail::ProxyFunctionRunnable<mozilla::MediaFormatReader::DemuxerProxy::NotifyDataArrived()::<lambda()>, mozilla::MozPromise<bool, mozilla::MediaResult, true> >::Run [dom/media/MediaFormatReader.cpp:1060]
#03: mozilla::TaskQueue::Runner::Run [xpcom/threads/TaskQueue.cpp:232]
#04: nsThreadPool::Run [xpcom/threads/nsThreadPool.cpp:226]
#05: nsThread::ProcessNextEvent [mfbt/Maybe.h:445]
#06: NS_ProcessNextEvent [xpcom/threads/nsThreadUtils.cpp:389]
#07: mozilla::ipc::MessagePumpForNonMainThreads::Run [ipc/glue/MessagePump.cpp:339]
#08: MessageLoop::RunInternal [ipc/chromium/src/base/message_loop.cc:239]
#09: MessageLoop::Run [ipc/chromium/src/base/message_loop.cc:505]
#10: nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:503]
#11: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:219]
#12: libpthread.so.0 + 0x76ba
#13: libc.so.6 + 0x10682d
#14: ??? (???:???)
ExceptionHandler::GenerateDump cloned child 16003
ExceptionHandler::SendContinueSignalToChild sent continue signal to child
ExceptionHandler::WaitForContinueSignal waiting for continue signal...

[15940] WARNING: Decoder=7f89ae029c00 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /home/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 405

This is basically

<video  id='...' class='crt-video crt-skin-default' poster='...' preload='none' muted data-crt-video data-crt-options='{"autoheight":null,"duration":95,"hdUrl":false,"filmstrip":{"url":"...","width":"200","height":"112"}}' ><source src="..." type="video/mp4"></video>

[15940] WARNING: Decoder=7f89ae029c00 Decode error: file /home/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 3399

Comment 2

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

There are older reports, but not as frequent before early March.
(And the spike on 11 April is happening on only 2 installs.)

There are similar (but fewer) crashes in WebMBufferedState::NotifyDataArrived, so maybe the issue is at a higher level.

I don't have useful ideas just yet; in past experiences it has been some race between shutdown (killing the demuxer) and new data arriving into that demuxer.

But Jean-Yves would know best about all this, and/or possibly JW?

(I'll have a deeper look if I find the time...)

Comment 3

[[:philipp]]

it's crashing in a codepath that was last touched in bug 1341454.

Comment 4

[Peter Chang[:pchang]]

Assign to blake to find owner.

Comment 5

[JW Wang [:jwwang] [:jw_wang]]

http://searchfox.org/mozilla-central/rev/313e5199bf58200f158c6fcbe193e41b88ed58a6/dom/media/MediaFormatReader.cpp#2899

The |!mDemuxerInitDone && !mDemuxerInitRequest.Exists()| check is suspicious to me. I think it should be just |!mDemuxerInitDone|.

Hi Jya,
Do you have any idea about the check?

Comment 6

[Jean-Yves Avenard [:jya]]

it does indeed look suspicious...

I can't recall why it was done that way

Comment 7

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review commit: https://reviewboard.mozilla.org/r/133400/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/133400/

Comment 8

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Thank you for looking into this, Jean-Yves.

Comment 9

[JW Wang [:jwwang] [:jw_wang]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

https://reviewboard.mozilla.org/r/133400/#review136546

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a5cb0de6bdb2
Abort if demuxer initialisation isn't complete. r=jwwang

Comment 11

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backed out for failing various media-related wpt tests, e.g. mediasource-activesourcebuffers.html:

https://hg.mozilla.org/integration/autoland/rev/2e03e6987fefcefbf0663866a91b09afdec83868

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=a5cb0de6bdb2ffe13eb41dc5a85f61d79d1606a9&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable

Please check the wpt failures.

Furthermore on Android, test_BufferedSeek.htm etc. fails: https://treeherder.mozilla.org/logviewer.html#?job_id=94442012&repo=autoland

Comment 12

[Jean-Yves Avenard [:jya]]

so it turned out that NotifyDataArrived is required for the MediaSourceDemuxer to resolve its promise, hence why we had the |!mDemuxerInitDone && !mDemuxerInitRequest.Exists()|

So it's definitely due to bug 1341454, the track demuxers are no longer created as it used to...

Comment 13

[Jean-Yves Avenard [:jya]]

A tad puzzled with the stack trace.

So we attempt to deference a null pointer.
However, https://hg.mozilla.org/mozilla-central/annotate/ce69b6e1773e/dom/media/MediaFormatReader.cpp#l1054 test that such pointer isn't null...

So there is a race between the test of the pointer value and accessing it. I don't see however how that could be possible.. the Data::mDemuxer is only ever accessed on its own taskqueue.

Comment 14

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review commit: https://reviewboard.mozilla.org/r/134418/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/134418/

Comment 15

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/133400/diff/1-2/

Comment 16

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

https://reviewboard.mozilla.org/r/134418/#review137456

Comment 17

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P3. Don't expect that all data has been processed after metadata.

Following P2, the init segment is processed as soon as it's available.

Assuming that the buffered range has been updated when loadedmetadata was fired was wrong. Only once the data has been fully appended to the source buffer, can seeking complete.

Review commit: https://reviewboard.mozilla.org/r/134528/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/134528/

Comment 18

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/133400/diff/2-3/

Comment 19

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134418/diff/1-2/

Comment 20

[Jean-Yves Avenard [:jya]]

:jwwang

I'm getting time out following P2 changed with the test dom/media/mediasource/test/test_EndedEvent.html

It seeks to currentTime = duration, and wait for the ended event which never comes:

however:
GECKO(30251) | [MediaPlayback #1]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::OnDemuxFailed: Failed to demux video, failure:2154692616
GECKO(30251) | [MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ScheduleUpdate: SchedulingUpdate(Video)
GECKO(30251) | [MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Processing update for Video
GECKO(30251) | [MediaPlayback #1]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::DrainDecoder: Requesting Video decoder to drain
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::NotifyNewOutput: Received new Video sample time:3967000 duration:34000
GECKO(30251) | [MediaPlayback #2]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::NotifyNewOutput: Done processing new Video samples
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ScheduleUpdate: SchedulingUpdate(Video)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Processing update for Video
GECKO(30251) | [MediaPlayback #2]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::ReturnOutput: Resolved data promise for Video [3967000, 4001000]
GECKO(30251) | [MediaPlayback #2]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::DrainDecoder: Requesting Video decoder to drain
GECKO(30251) | [MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ScheduleUpdate: SchedulingUpdate(Video)
GECKO(30251) | [MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Processing update for Video
GECKO(30251) | [MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Update(Video) ni=0 no=0 in:12 out:12 qs=0 decoding:0 flushing:0 desc:ffvpx video decoder pending:0 waiting:0 sid:0
GECKO(30251) | [MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: No need for additional input (pending:0)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::RequestVideoData: RequestVideoData(0, 4000000)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ScheduleUpdate: SchedulingUpdate(Video)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Processing update for Video
GECKO(30251) | [MediaPlayback #2]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Rejecting Video promise: EOS
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Update(Video) ni=0 no=1 in:12 out:12 qs=0 decoding:0 flushing:0 desc:ffvpx video decoder pending:0 waiting:0 sid:0
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: No need for additional input (pending:0)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ReleaseResources:
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ShutdownDecoder: Audio
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ShutdownDecoder: Video
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ScheduleUpdate: SchedulingUpdate(Video)
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Processing update for Video
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: Update(Video) ni=0 no=0 in:0 out:0 qs=0 decoding:0 flushing:0 desc:shutdown pending:0 waiting:0 sid:0
GECKO(30251) | [MediaPlayback #2]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::Update: No need for additional input (pending:0)
GECKO(30251) | [Main Thread]: D/MediaSource MediaSourceResource(0x12a57c080:application/x.mediasource)::IsSuspendedByCache: UNIMPLEMENTED FUNCTION at /Users/jyavenard/Work/Mozilla/mozilla-central/dom/media/mediasource/MediaSourceResource.h:49
GECKO(30251) | --DOMWINDOW == 15 (0x18d9c8800) [pid = 30251] [serial = 15] [outer = 0x0] [url = about:blank]
GECKO(30251) | --DOMWINDOW == 14 (0x18d907000) [pid = 30251] [serial = 14] [outer = 0x0] [url = about:blank]
GECKO(30251) | --DOMWINDOW == 13 (0x185a5e000) [pid = 30251] [serial = 8] [outer = 0x0] [url = about:blank]
GECKO(30251) | --DOMWINDOW == 12 (0x12ac6b800) [pid = 30251] [serial = 11] [outer = 0x0] [url = about:blank]
Failed to retrieve MOZ_UPLOAD_DIR env var
4 INFO TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_EndedEvent.html | Test timed out. 
    reportError@SimpleTest/TestRunner.js:121:7
    TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
    TestRunner.runTests@SimpleTest/TestRunner.js:380:5
    RunSet.runtests@SimpleTest/setup.js:194:3
    RunSet.runall@SimpleTest/setup.js:173:5
    hookupTests@SimpleTest/setup.js:266:5
EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
    hookup@SimpleTest/setup.js:246:5
EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Fvar%2Ffolders%2Fgd%2Fdg_9jpsd44118kp5cns1rp5c0000gn%2FT:11:1
GECKO(30251) | [Main Thread]: D/MediaSource MediaSourceDecoder(0x10d85e800)::Shutdown: Shutdown
GECKO(30251) | [Main Thread]: D/MediaSource MediaSource(0x12a7eeb40)::Detach: mDecoder=0x10d85e800 owner=0x12a04e890
GECKO(30251) | [Main Thread]: D/MediaSource MediaSource(0x12a7eeb40)::SetReadyState: SetReadyState(aState=0) mReadyState=2
GECKO(30251) | [Main Thread]: D/MediaSource MediaSource(0x12a7eeb40)::QueueAsyncSimpleEvent: Queuing event 'sourceclose'
GECKO(30251) | [Main Thread]: D/MediaSource SourceBuffer(0x1357cb680:video/webm)::Detach: Detach
GECKO(30251) | [Main Thread]: D/MediaSource TrackBuffersManager(0x129893000:video/webm)::Detach:
GECKO(30251) | [Main Thread]: D/MediaSource SourceBufferList(0x1296dc300)::QueueAsyncSimpleEvent: Queue event 'removesourcebuffer'
GECKO(30251) | [Main Thread]: D/MediaSource SourceBuffer(0x1357cb680:video/webm)::Detach: Detach
GECKO(30251) | [Main Thread]: D/MediaSource SourceBuffer(0x1357cb680:video/webm)::Detach: Already detached
GECKO(30251) | [Main Thread]: D/MediaSource SourceBufferList(0x1296dc280)::QueueAsyncSimpleEvent: Queue event 'removesourcebuffer'
GECKO(30251) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
GECKO(30251) | MEMORY STAT | vsize 5747MB | residentFast 503MB | heapAllocated 114MB
GECKO(30251) | [MediaPlayback #4]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ResetDecode:
GECKO(30251) | [MediaPlayback #4]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::Reset: Reset(Video) BEGIN
GECKO(30251) | [MediaPlayback #4]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::Reset: Reset(Video) END
GECKO(30251) | Decoder=10d85e800 MediaDecoder State: channels=0 rate=0 hasAudio=0 hasVideo=1 mPlayState=PAUSED mdsm=129fa9000
GECKO(30251) | reader data:
GECKO(30251) | Audio Decoder: unavailable
GECKO(30251) | Audio Frames Decoded: 0
GECKO(30251) | Video Decoder: shutdown
GECKO(30251) | Hardware Video Decoding: disabled
GECKO(30251) | Video Frames Decoded: 12 (skipped=0)
GECKO(30251) | Video State: ni=0 no=0 wp=0 demuxr=0 demuxq=0 decoder=0 tt=-1.0 tths=-1 in=0 out=0 qs=0 pending:0 wfd=0 wfk=0 sid=0
GECKO(30251) | Dumping Data for Demuxer: 128e53000
GECKO(30251) | 	Dumping Video Track Buffer(video/webm; codecs=vp8): mLastVideoTime=4.001000
GECKO(30251) | 		Video Track Buffer Details: NumSamples=120 Size=250502 Evictable=226862 NextGetSampleIndex=120 NextInsertionIndex=120
GECKO(30251) | 		Video Track Buffered: ranges=[(0.000000, 4.001000)]
GECKO(30251) | [MediaPlayback #5]: D/MediaSource TrackBuffersManager(0x129893000:video/webm)::Seek: Keyframe  found at 0 @ 0
GECKO(30251) | [MediaPlayback #4]: D/MediaFormatReader MediaFormatReader(0x129f2a000)::Shutdown:
GECKO(30251) | Decoder=10d85e800 MediaDecoderStateMachine State: GetMediaTime=4000000 GetClock=-1 mMediaSink=10b057c90 state=COMPLETED mPlayState=2 mSentFirstFrameLoadedEvent=1 IsPlaying=0 mAudioStatus=idle mVideoStatus=idle mDecodedAudioEndTime=0 mDecodedVideoEndTime=4001000mAudioCompleted=0 mVideoCompleted=0
GECKO(30251) | VideoSink Status: IsStarted=0 IsPlaying=0 VideoQueue(finished=1 size=1) mVideoFrameEndTime=0 mHasVideo=0 mVideoSinkEndRequest.Exists()=0 mEndPromiseHolder.IsEmpty()=1
GECKO(30251) | [MediaPlayback #4]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ShutdownDecoder: Video
GECKO(30251) | [MediaPlayback #5]: D/MediaSource TrackBuffersManager(0x129893000:video/webm)::Seek: Keyframe  found at 0 @ 0
GECKO(30251) | [MediaPlayback #4]: V/MediaFormatReader MediaFormatReader(0x129f2a000)::ReleaseResources:
GECKO(30251) | [Main Thread]: D/MediaSource MediaSource(0x12a7eeb40)::DispatchSimpleEvent: Dispatch event 'sourceclose'
GECKO(30251) | [Main Thread]: D/MediaSource SourceBufferList(0x1296dc300)::DispatchSimpleEvent: Dispatch event 'removesourcebuffer'
GECKO(30251) | [Main Thread]: D/MediaSource SourceBufferList(0x1296dc280)::DispatchSimpleEvent: Dispatch event 'removesourcebuffer'
5 INFO TEST-OK | dom/media/mediasource/test/test_EndedEvent.html | took 319753ms


This shows that the MFR has decoded the last video frame and returned EOS.
Yet, the MDSM shows mVideoCompleted=0 with state=COMPLETED

Per spec:
we are to reach ended playback:
https://html.spec.whatwg.org/multipage/embedded-content.html#ended-playback
"When the current playback position reaches the end of the media resource when the direction of playback is forwards, then the user agent must follow these steps"

we have reached the end of the media resource and the direction of playback is forward:
https://html.spec.whatwg.org/multipage/embedded-content.html#direction-of-playback
"If the element's playbackRate is positive or zero, then the direction of playback is forwards"

Comment 21

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8862663 [details]
Bug 1357040: P3. Don't expect that all data has been processed after metadata.

https://reviewboard.mozilla.org/r/134528/#review137496

Comment 22

[JW Wang [:jwwang] [:jw_wang]]

I am able to repro the issue on my desktop with
`MOZ_CHAOSMODE=0./mach mochitest dom/media/mediasource/test/test_EndedEvent.html --run-until-failure --repeat 10000`.

http://searchfox.org/mozilla-central/rev/068e6f292503df13515a52321fc3844e237bf6a9/dom/media/MediaDecoderStateMachine.cpp#2391

The if statement is expected to be true for the test but sometimes it fails with newCurrentTime=4000000 and mMaster->Duration()=4001000.

It looks like the duration (4000000) is updated again (to 4001000) after the 'loadedmetadata' event is fired.

Comment 23

[Jean-Yves Avenard [:jya]]

oh I see what's happening....

the metadata states a 4s video, but the last video frame is 4.00100

yet, we got EOS, so shouldn't we fire ended anyway?

Comment 24

[JW Wang [:jwwang] [:jw_wang]]

No, 'ended' is fired when playback reaches the end of stream, not when decoder reaches EOS. In this case, the playback position after seeking is 4s, and there is still 0.001s to go before reaching the end.

Comment 25

[Jean-Yves Avenard [:jya]]

I understand that. However in webm the duration of the last video frame is estimated. So there's often a discrepancy between the time reported in the metadata and the end time of the last frame.

Maybe I could add a workaround with MSE that if we reach the last frame of the container and the duration in the metadata is close. Then round up to duration.

Comment 26

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P4. Don't assume the duration found when reading metadata will be the final one.

When endOfStream() is called, the duration is changed to that of the last buffered frame's end time.

The ended event will only be fired if currentTime is equal to the duration. So if the duration has changed following a call to endOfStream, then playback won't be considered as ended.

Review commit: https://reviewboard.mozilla.org/r/134764/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/134764/

Comment 27

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P5. Remove unecessary code.

We have no need to call endOfStream here as we don't rely on the ended event being fired.
Also, there's no need to track how many update count we will get when we only use appendBuffer once.

Adding extra test to help identify where the actual failure of the test could occur.

Review commit: https://reviewboard.mozilla.org/r/134766/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/134766/

Comment 28

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P6. Don't assume that when stalling all data has been loaded.

The stalled event can be fired as playback is starting and data has yet to be processed.
So instead we wait for playback to reach the end.

Review commit: https://reviewboard.mozilla.org/r/134768/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/134768/

Comment 29

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134418/diff/2-3/

Comment 30

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862663 [details]
Bug 1357040: P3. Don't expect that all data has been processed after metadata.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134528/diff/1-2/

Comment 31

[Jean-Yves Avenard [:jya]]

Gerald, could you review P2 again...

I was afraid there was a race in accessing the MediaSourceDemuxer object.

MediaSourceDecoder::GetDemuxer() returns a raw pointer of its mDemuxer value. This mDemuxer can be reset on the main thread and we were accessing on the MediaSourceDemuxer taskqueue.

So I now store a copy of the pointers and protect it via a mutex. Should the sourcebuffer be detached, that pointer is cleared and we test that value.

I thought of doing something like:

RefPtr<MediaSourceDemuxer> msDemuxer = mParentDecoder->GetDemuxer();

however, I was afraid that on the event MediaSourceDecoder::mDemuxer is cleared, right when having msDemuxer set, we could end up with a cycle (the MediaSourceDemuxer holds a strong reference to the TrackBufferManager)

Comment 32

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8862890 [details]
Bug 1357040: P4. Don't assume the duration found when reading metadata will be the final one.

https://reviewboard.mozilla.org/r/134764/#review137806

Comment 33

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8862891 [details]
Bug 1357040: P5. Remove unecessary code.

https://reviewboard.mozilla.org/r/134766/#review137808

Comment 34

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8862892 [details]
Bug 1357040: P6. Don't assume that when stalling all data has been loaded.

https://reviewboard.mozilla.org/r/134768/#review137810

Comment 35

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Jean-Yves Avenard [:jya] from comment #31)
> Gerald, could you review P2 again...

Done, still r+.

I agree it's better to just avoid cycles where possible. So having this raw pointer protected by a mutex seems better to me.

Comment 36

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/133400/diff/3-4/

Comment 37

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134418/diff/3-4/

Comment 38

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862663 [details]
Bug 1357040: P3. Don't expect that all data has been processed after metadata.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134528/diff/2-3/

Comment 39

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862890 [details]
Bug 1357040: P4. Don't assume the duration found when reading metadata will be the final one.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134764/diff/1-2/

Comment 40

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862891 [details]
Bug 1357040: P5. Remove unecessary code.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134766/diff/1-2/

Comment 41

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862892 [details]
Bug 1357040: P6. Don't assume that when stalling all data has been loaded.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134768/diff/1-2/

Comment 42

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1357040: P7. Only use sourcebuffer again once previous operation completed.

It was incorrect to assume that once "loadeddata" event fired the sourcebuffer would be usable again. Only the "updateend" event guarantees such condition.

Review commit: https://reviewboard.mozilla.org/r/135768/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/135768/

Comment 43

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/133400/diff/4-5/

Comment 44

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134418/diff/4-5/

Comment 45

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862663 [details]
Bug 1357040: P3. Don't expect that all data has been processed after metadata.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134528/diff/3-4/

Comment 46

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862890 [details]
Bug 1357040: P4. Don't assume the duration found when reading metadata will be the final one.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134764/diff/2-3/

Comment 47

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862891 [details]
Bug 1357040: P5. Remove unecessary code.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134766/diff/2-3/

Comment 48

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862892 [details]
Bug 1357040: P6. Don't assume that when stalling all data has been loaded.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134768/diff/2-3/

Comment 49

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8864053 [details]
Bug 1357040: P7. Only use sourcebuffer again once previous operation completed.

https://reviewboard.mozilla.org/r/135768/#review139008

Comment 50

[Blake Wu [:bwu][:blakewu]]

Jya, 
This bug caused many crashes. Can we land it now?

Comment 51

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/133400/diff/5-6/

Comment 52

[Jean-Yves Avenard [:jya]]

Comment on attachment 8862527 [details]
Bug 1357040: P2. Don't rely on NotifyDataArrived to resolve MSE init promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/134418/diff/5-6/

Comment 53

[Jean-Yves Avenard [:jya]]

Moving all the mochitests changes to bug 1362165

Comment 54

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f0e461394f7e
P1. Abort if demuxer initialisation isn't complete. r=jwwang
https://hg.mozilla.org/integration/autoland/rev/23327af4c4c7
P2. Don't rely on NotifyDataArrived to resolve MSE init promise. r=gerald

Comment 55

[Iris Hsiao [:ihsiao]]

https://hg.mozilla.org/mozilla-central/rev/f0e461394f7e
https://hg.mozilla.org/mozilla-central/rev/23327af4c4c7

Comment 56

[Gerry Chang [:gchang]]

Track 54+/55+ as the volume of crashes in 54 is a bit high.

Comment 57

[Jean-Yves Avenard [:jya]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Approval Request Comment
[Feature/Bug causing the regression]: bug 1341454
[User impact if declined]: Crashes
[Is this code covered by automated tests?]: yes
[Has the fix been verified in Nightly?]: it's an intermittent failure. It's also hard to say as all the crashes lately have been in 54 not 55.
[Needs manual test from QE? If yes, steps to reproduce]: no
[List of other uplifts needed for the feature/fix]: both patches are required
[Is the change risky?]: no
[Why is the change risky/not risky?]: we abort an operation early if not initialised.
[String changes made/needed]: none

Comment 58

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

54 is on Beta.

Comment 59

[Gerry Chang [:gchang]]

Comment on attachment 8861408 [details]
Bug 1357040: P1. Abort if demuxer initialisation isn't complete.

Fix a crash. Beta54+. Should be in 54 beta 8.

Comment 60

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/82aba3466ff1
https://hg.mozilla.org/releases/mozilla-beta/rev/4dc1982e436e

Comment 61

[Andrei Vaida [:avaida]]

(In reply to Jean-Yves Avenard [:jya] from comment #57)
> [Is this code covered by automated tests?]: yes
> [Has the fix been verified in Nightly?]: it's an intermittent failure. It's
> also hard to say as all the crashes lately have been in 54 not 55.
> [Needs manual test from QE? If yes, steps to reproduce]: no

Setting qe-verify- based on jya's assessment on manual testing needs and the fact that this fix has automated coverage.

Comment 62

[[:philipp]]

hi, there are still crashes with this signature in 54.0b8 after the patch landed there:
https://crash-stats.mozilla.com/signature/?product=Firefox&version=54.0b8&signature=mozilla%3A%3AMP4Demuxer%3A%3ANotifyDataArrived#reports

Comment 63

[Jean-Yves Avenard [:jya]]

(In reply to [:philipp] from comment #62)
> hi, there are still crashes with this signature in 54.0b8 after the patch
> landed there:
> https://crash-stats.mozilla.com/signature/?product=Firefox&version=54.
> 0b8&signature=mozilla%3A%3AMP4Demuxer%3A%3ANotifyDataArrived#reports

fixed in bug 1366208 (hopefully)

Comment 64

[[:philipp]]

thanks :))