Closed Bug 1269408 Opened 8 years ago Closed 8 years ago

Intermittent test_eme_canvas_blocked.html | application crashed [@ <lambda_59b20a6e106f0836eb5216a8b94b4d02>::operator()]

Categories

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

Product:
Core
Component:
Audio/Video: Playback
Version:
49 Branch
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla49
Tracking Flags:
Tracking Status
firefox46 --- wontfix
firefox47 - wontfix
firefox48 + wontfix
firefox49 --- fixed

People

(Reporter: KWierso, Assigned: jya)

References

Details

(Keywords: intermittent-failure)

Attachments

(9 files)

MozReview Request: Bug 1269408: P2. Update mochitest. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P4. Ensure the decoders are flushed prior performing an internal seek. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P5. Only drop the seek target if it's exactly the seek target. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P7. Start skip to next keyframe logic when resume point is behind current time. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P8. Add debugging log. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details
MozReview Request: Bug 1269408: P9. Move handling logic of skip to next keyframe to its own function. r?gerald
58 bytes, text/x-review-board-request
mozbugz
: review+
Details 
Assertion failure: decoder.mTimeThreshold, at c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/src/dom/media/MediaFormatReader.cpp:1016
Flags: needinfo?(jyavenard)
Assignee: nobody → jyavenard
Flags: needinfo?(jyavenard)
Priority: P5 → P2
Component: Audio/Video → Audio/Video: Playback
Priority: P2 → P1
Comment on attachment 8748524 [details]
MozReview Request: Bug 1269408: P2. Update mochitest. r?gerald

https://reviewboard.mozilla.org/r/50345/#review47205
Attachment #8748524 - Flags: review?(gsquelart) → review+
It was possible for the variable to be used uninitialized.

Review commit: https://reviewboard.mozilla.org/r/50711/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/50711/
Attachment #8748524 - Attachment description: MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald → MozReview Request: Bug 1269408: P2. Update mochitest. r?gerald
Attachment #8749041 - Flags: review?(gsquelart)
Attachment #8749042 - Flags: review?(gsquelart)
Attachment #8749043 - Flags: review?(gsquelart)
Attachment #8749044 - Flags: review?(gsquelart)
Attachment #8749045 - Flags: review?(gsquelart)
Some decoders (WMF) keep some internal counters on how many frames have been output and use this to calculate the time of the decoded audio frame. As such, when internally seeking, the next frame decoded would have always been past the seek target.

Review commit: https://reviewboard.mozilla.org/r/50715/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/50715/
If the Skip To Next Keyframe logic was activated, the next frame demuxed would have been passed the internal seek target, causing it to be unnecessarily dropped.

Review commit: https://reviewboard.mozilla.org/r/50717/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/50717/
Access to some members is not thread-safe; but the typical use of those informations is when a mochitest has timed out, and by that time the MFR will have been idled for over 5 minutes.

Review commit: https://reviewboard.mozilla.org/r/50719/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/50719/
Comment on attachment 8748524 [details]
MozReview Request: Bug 1269408: P2. Update mochitest. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50345/diff/1-2/
Comment on attachment 8749041 [details]
MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50711/diff/1-2/
Attachment #8749041 - Attachment description: MozReview Request: Bug 1269408: [MSE] P3. Initialise variable. r?gerald → MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald
Attachment #8749042 - Attachment description: MozReview Request: Bug 1269408: P4. Ensure a new seek request will cancel the previous internal seek. r?gerald → MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald
Comment on attachment 8749042 [details]
MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50713/diff/1-2/
Comment on attachment 8749043 [details]
MozReview Request: Bug 1269408: P4. Ensure the decoders are flushed prior performing an internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50715/diff/1-2/
Comment on attachment 8749044 [details]
MozReview Request: Bug 1269408: P5. Only drop the seek target if it's exactly the seek target. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50717/diff/1-2/
Comment on attachment 8749045 [details]
MozReview Request: Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50719/diff/1-2/
Attachment #8749041 - Flags: review?(gsquelart) → review+
Comment on attachment 8749041 [details]
MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald

https://reviewboard.mozilla.org/r/50711/#review47435
Comment on attachment 8749042 [details]
MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald

https://reviewboard.mozilla.org/r/50713/#review47439

::: dom/media/MediaFormatReader.cpp:838
(Diff revision 2)
> +  if (!mSeekPromise.IsEmpty()) {
> +    MOZ_ASSERT(!decoder.HasPromise());
> +    MOZ_DIAGNOSTIC_ASSERT(!mAudio.mTimeThreshold && !mVideo.mTimeThreshold,
> +                          "InternalSeek must have been aborted when Seek was first called");
> +    MOZ_DIAGNOSTIC_ASSERT(!mAudio.HasWaitingPromise() && !mVideo.HasWaitingPromise(),
> +                          "Waiting promises must have been rejects when seek was first called");

'rejects' -> 'rejected'
Attachment #8749042 - Flags: review?(gsquelart) → review+
Comment on attachment 8749043 [details]
MozReview Request: Bug 1269408: P4. Ensure the decoders are flushed prior performing an internal seek. r?gerald

https://reviewboard.mozilla.org/r/50715/#review47441
Attachment #8749043 - Flags: review?(gsquelart) → review+
Comment on attachment 8749044 [details]
MozReview Request: Bug 1269408: P5. Only drop the seek target if it's exactly the seek target. r?gerald

https://reviewboard.mozilla.org/r/50717/#review47443
Attachment #8749044 - Flags: review?(gsquelart) → review+
Comment on attachment 8749045 [details]
MozReview Request: Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald

https://reviewboard.mozilla.org/r/50719/#review47447

::: dom/media/MediaFormatReader.cpp:1788
(Diff revision 2)
> +  result += nsPrintfCString("MFR: audio: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
> +                            NeedInput(mAudio), mAudio.HasPromise(), mAudio.mInputExhausted,
> +                            mAudio.mDemuxRequest.Exists(), int32_t(mAudio.mQueuedSamples.Length()),
> +                            mAudio.mDecodingRequested, mAudio.mTimeThreshold.isSome() ? mAudio.mTimeThreshold.ref().mTime.ToSeconds() : -1.0,
> +                            mAudio.mTimeThreshold.isSome() ? mAudio.mTimeThreshold.ref().mHasSeeked : -1,
> +                            mAudio.mNumSamplesInput, mAudio.mNumSamplesOutput,
> +                            uint32_t(size_t(mAudio.mSizeOfQueue)), uint32_t(mAudio.mOutput.Length()),
> +                            mAudio.mWaitingForData, mAudio.mLastStreamSourceID);
> +  result += nsPrintfCString("MFR: video: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
> +                            NeedInput(mVideo), mVideo.HasPromise(), mVideo.mInputExhausted,
> +                            mVideo.mDemuxRequest.Exists(), int32_t(mVideo.mQueuedSamples.Length()),
> +                            mVideo.mDecodingRequested, mVideo.mTimeThreshold.isSome() ? mVideo.mTimeThreshold.ref().mTime.ToSeconds() : -1.0,
> +                            mVideo.mTimeThreshold.isSome() ? mVideo.mTimeThreshold.ref().mHasSeeked : -1,
> +                            mVideo.mNumSamplesInput, mVideo.mNumSamplesOutput,
> +                            uint32_t(size_t(mVideo.mSizeOfQueue)), uint32_t(mVideo.mOutput.Length()),
> +                            mVideo.mWaitingForData, mVideo.mLastStreamSourceID);

I believe "%d" expects an int (not int32_t), "%u" expects an unsigned int (not uint32_t), so the casts may be incorrect.
Or you may use PRId32 and PRIu32 (in between the format string fragments).
"%zu" might work for size_t.

::: dom/media/MediaFormatReader.cpp:1791
(Diff revision 2)
>                              mVideo.mNumSamplesOutputTotal,
>                              mVideo.mNumSamplesSkippedTotal);
> +  result += nsPrintfCString("MFR: audio: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
> +                            NeedInput(mAudio), mAudio.HasPromise(), mAudio.mInputExhausted,
> +                            mAudio.mDemuxRequest.Exists(), int32_t(mAudio.mQueuedSamples.Length()),
> +                            mAudio.mDecodingRequested, mAudio.mTimeThreshold.isSome() ? mAudio.mTimeThreshold.ref().mTime.ToSeconds() : -1.0,

Overlong line.

::: dom/media/MediaFormatReader.cpp:1799
(Diff revision 2)
> +                            uint32_t(size_t(mAudio.mSizeOfQueue)), uint32_t(mAudio.mOutput.Length()),
> +                            mAudio.mWaitingForData, mAudio.mLastStreamSourceID);
> +  result += nsPrintfCString("MFR: video: ni=%d no=%d ie=%d demuxr:%d demuxq:%d decoder:%d tt:%f tths:%d in:%llu out:%llu qs=%u pending:%u waiting:%d sid:%u\n",
> +                            NeedInput(mVideo), mVideo.HasPromise(), mVideo.mInputExhausted,
> +                            mVideo.mDemuxRequest.Exists(), int32_t(mVideo.mQueuedSamples.Length()),
> +                            mVideo.mDecodingRequested, mVideo.mTimeThreshold.isSome() ? mVideo.mTimeThreshold.ref().mTime.ToSeconds() : -1.0,

Overlong line.
Attachment #8749045 - Flags: review?(gsquelart) → review+
Comment on attachment 8749042 [details]
MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50713/diff/2-3/
Comment on attachment 8749043 [details]
MozReview Request: Bug 1269408: P4. Ensure the decoders are flushed prior performing an internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50715/diff/2-3/
Comment on attachment 8749044 [details]
MozReview Request: Bug 1269408: P5. Only drop the seek target if it's exactly the seek target. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50717/diff/2-3/
Comment on attachment 8749045 [details]
MozReview Request: Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50719/diff/2-3/
There is no point decoding up to the internal seek time if it's already behind the current playback time.

Review commit: https://reviewboard.mozilla.org/r/51027/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/51027/
Attachment #8749539 - Flags: review?(gsquelart)
Attachment #8749540 - Flags: review?(gsquelart)
Attachment #8749541 - Flags: review?(gsquelart)
Almost everytime I had to debug the MFR, I had to print those details.

Review commit: https://reviewboard.mozilla.org/r/51029/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/51029/
Comment on attachment 8749041 [details]
MozReview Request: Bug 1269408: P1. Retry InternalSeek if previous attempt failed once more data is available. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50711/diff/2-3/
Comment on attachment 8748524 [details]
MozReview Request: Bug 1269408: P2. Update mochitest. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50345/diff/2-3/
Comment on attachment 8749042 [details]
MozReview Request: Bug 1269408: P3. Ensure a new seek request will cancel the previous internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50713/diff/3-4/
Comment on attachment 8749043 [details]
MozReview Request: Bug 1269408: P4. Ensure the decoders are flushed prior performing an internal seek. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50715/diff/3-4/
Comment on attachment 8749044 [details]
MozReview Request: Bug 1269408: P5. Only drop the seek target if it's exactly the seek target. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50717/diff/3-4/
Comment on attachment 8749045 [details]
MozReview Request: Bug 1269408: P6. Add debugging information, useful when a mochitest timeout. r?gerald

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/50719/diff/3-4/
https://reviewboard.mozilla.org/r/50715/#review47687

::: dom/media/MediaFormatReader.h:341
(Diff revision 4)
>        mSeekRequest.DisconnectIfExists();
>        mTrackDemuxer->Reset();
> +      mQueuedSamples.Clear();
> +    }
> +
> +    // Flush the decoder if any and reset decoding related data.

"if any" ... what?
Attachment #8749539 - Flags: review?(gsquelart) → review+
Comment on attachment 8749539 [details]
MozReview Request: Bug 1269408: P7. Start skip to next keyframe logic when resume point is behind current time. r?gerald

https://reviewboard.mozilla.org/r/51027/#review47689
Comment on attachment 8749540 [details]
MozReview Request: Bug 1269408: P8. Add debugging log. r?gerald

https://reviewboard.mozilla.org/r/51029/#review47691
Attachment #8749540 - Flags: review?(gsquelart) → review+
Attachment #8749541 - Flags: review?(gsquelart) → review+
Comment on attachment 8749541 [details]
MozReview Request: Bug 1269408: P9. Move handling logic of skip to next keyframe to its own function. r?gerald

https://reviewboard.mozilla.org/r/51031/#review47693
https://reviewboard.mozilla.org/r/50715/#review47687

> "if any" ... what?

Oh, if any decoder. How about "Flush the decoder if present, and reset...".
[Tracking Requested - why for this release]:

While the assert showing in the title won't affect 48 and earlier. The reason for this crash was due to the fix in bug 1269178 which was backed out; and this bug contains a new version of it. 

This needs to be uplift in 47 as overall the potential stalls are due to a regression introduced in 46
status-firefox46: --- → wontfix
status-firefox47: --- → affected
status-firefox48: --- → affected
tracking-firefox47: --- → ?
Given the size of the changes here, I do not think we have the runway to take it in Beta47. Please let me know if there are any concerns.
status-firefox47: affected → wontfix
tracking-firefox47: ? → -
tracking-firefox48: --- → ?
Is this something we should consider backporting to 48 still?
Flags: needinfo?(jyavenard)
It would be nice. But there's been extensive changes done in 49 on issues discovered from this (all related). I don't know how confident I would be in uplifting the lot and not miss some
Flags: needinfo?(jyavenard)
See Also: → 1269178
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: