Closed Bug 1274933 Opened 6 years ago Closed 6 years ago
_Resume After Clearing _mp4 .html | Test timed out .
MozReview Request: Bug 1274933: Reject data promise when EOS is encountered following waiting for data. r?gerald
58 bytes, text/x-review-board-request
Likely very similar to bug 1270323, symptoms are similar but somehow the fix of bug 1270323 doesn't fix it. Logs show that: audio state: ni=0 no=0 ie=1 demuxr:0 demuxq:0 decoder:1 tt:-1.000000 tths:-1 in:1 out:1 qs=0 pending:0 waiting:1 rnewdata:1 sid:27 So we are in waiting mode, it is marked as having new data received, yet the waiting promise wasn't resolved:  WARNING: Decoder=110d2e80 GetMediaTime=1623945 GetClock=1623945 mState=DECODING mPlayState=3 mDecodingFirstFrame=0 IsPlaying=1 mAudioStatus=waiting mVideoStatus=idle mDecodedAudioEndTime=1625395 mDecodedVideoEndTime=1963333 mIsAudioPrerolling=0 mIsVideoPrerolling=0: Unfortunately, I've only seen it happening twice, going to be hard to reproduce
6 years ago
Priority: -- → P5
Actually looking at the log, this is potentially very troublesome. It shows that if decoding is fast and we get to the end of the trackbuffer while we're in the middle of processing an appendBuffer and between two media segments: we will stall and playback will not recover. example: 04:50:01 INFO - audio state: ni=0 no=0 ie=1 demuxr:0 demuxq:0 decoder:1 tt:-1.000000 tths:-1 in:1 out:1 qs=0 pending:0 waiting:1 rnewdata:1 sid:28 04:50:01 INFO - video decoder: wmf software video decoder 04:50:01 INFO - hardware video decoding: disabled 04:50:01 INFO - video frames decoded: 71 (skipped:0) 04:50:01 INFO - video state: ni=0 no=0 ie=1 demuxr:0 demuxq:0 decoder:1 tt:-1.000000 tths:-1 in:72 out:72 qs=1 pending:1 waiting:0 rnewdata:0 sid:29 04:50:01 INFO - mDemuxEOS=1 mOutputRequested=1 mNeedDraining=0 mDraining=1 mDrainComplete=1Dumping data for demuxer eba2220: 04:50:01 INFO - Dumping Audio Track Buffer(audio/mp4a-latm): - mLastAudioTime: 6.826666 04:50:01 INFO - NumSamples:84 Size:17668 NextGetSampleIndex:4294967295 NextInsertionIndex:84 04:50:01 INFO - Buffered: ranges=[(3.900952, 7.801904)] 04:50:01 INFO - Dumping Video Track Buffer(video/avc) - mLastVideoTime: 7.208333 04:50:01 INFO - NumSamples:96 Size:107347 NextGetSampleIndex:96 NextInsertionIndex:96 04:50:01 INFO - Buffered: ranges=[(4.005000, 7.208333)] so here we have audio stuck at 6.826666s. 6.826666 is the end time of the 3rd media segment being processed It's a very narrow gap during which the error can occur as a new task is immediately dispatched to process the next media segment (the appendBuffer adds 2 media segments at once). So I'm marking this as P2 because that needs to be tackled asap.
Priority: P5 → P2
just seen with mochitest dom/media/mediasource/test/test_SeekNoData_mp4.html | Test timed out. same observed behaviour, stall occurs with data in the middle of an append buffer.
Review commit: https://reviewboard.mozilla.org/r/54814/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/54814/
Attachment #8755791 - Flags: review?(gsquelart)
Comment on attachment 8755791 [details] MozReview Request: Bug 1274933: Reject data promise when EOS is encountered following waiting for data. r?gerald https://reviewboard.mozilla.org/r/54814/#review51476
Attachment #8755791 - Flags: review?(gsquelart) → review+
Hoping I nailed all the MSE intermittents now: https://treeherder.mozilla.org/#/jobs?repo=try&revision=ffb21cfdad5e8bc3499f055e10738631b33c532b Looks very good
You need to log in before you can comment on or make changes to this bug.