mediasource-duration.html intermittently failing when decode ahead is set to high values

RESOLVED FIXED in Firefox 49

Status

()

defect
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: jya, Assigned: jya)

Tracking

(Blocks 1 bug, {regression})

42 Branch
mozilla51
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox48 wontfix, firefox49 fixed, firefox50 fixed, firefox51 fixed)

Details

Attachments

(3 attachments)

Assignee

Description

3 years ago
noticed while debugging an intermittent in the web-platform-test mediasource-duration.html and attempting to find why we've had report for the "ended" event to never be fired.

something isn't quite right.

Set media.video-decode-ahead to 30.

We have reached the end of the data, and the decoder has been drained. There are now 27 frames pending to be returned to the MDSM.
The last frame returned to the MDSM had a time of 365200.

duration was set to 0.510839. The ended event is never fired.

[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::NotifyNewOutput: Received new Video sample time:1294800 duration:33200
[MediaPlayback #1]: D/MediaFormatReader MediaFormatReader(139d53000)::NotifyDrainComplete: Video
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Processing update for Video
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Update(Video) ni=0 no=0 ie=1, in:38 out:38 qs=27 pending:27 waiting:1 ahead:1 sid:0
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Still waiting for data.
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Processing update for Audio
[MediaPlayback #1]: D/MediaFormatReader MediaFormatReader(139d53000)::Update: Rejecting Audio promise: WAITING_FOR_DATA
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Update(Audio) ni=0 no=1 ie=1, in:29 out:29 qs=0 pending:0 waiting:1 ahead:1 sid:0
[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Still waiting for data.
[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(139d53000)::ScheduleUpdate: SchedulingUpdate(Audio)
[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Processing update for Audio
[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Update(Audio) ni=0 no=0 ie=1, in:29 out:29 qs=0 pending:0 waiting:1 ahead:1 sid:0
[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(139d53000)::Update: Still waiting for data.
[Main Thread]: D/MediaSource SourceBuffer(139d3ad00:video/mp4)::DispatchSimpleEvent: Dispatch event 'updatestart'
[Main Thread]: D/MediaSource SourceBuffer(139d3ad00:video/mp4)::QueueAsyncSimpleEvent: Queuing event 'update'
[Main Thread]: D/MediaSource SourceBuffer(139d3ad00:video/mp4)::QueueAsyncSimpleEvent: Queuing event 'updateend'
[Main Thread]: D/MediaSource SourceBuffer(139d3ad00:video/mp4)::DispatchSimpleEvent: Dispatch event 'update'
[Main Thread]: D/MediaSource SourceBuffer(139d3ad00:video/mp4)::DispatchSimpleEvent: Dispatch event 'updateend'
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::SetDuration: SetDuration(aDuration=0.500000, ErrorResult)
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::DurationChange: DurationChange(aNewDuration=0.500000)
[Main Thread]: D/MediaSource TrackBuffersManager(12ea0b000:video/mp4)::Buffered: 
[Main Thread]: V/MediaSource SourceBuffer(139d3ad00:video/mp4)::GetBuffered: intersection=[(0.033200, 0.510839)]
[Main Thread]: D/MediaSource MediaSourceResource(12fbd5180:)::GetLength: UNIMPLEMENTED FUNCTION at /Users/jyavenard/Work/Mozilla/mozilla-central/dom/media/mediasource/MediaSourceResource.h:43
[Main Thread]: D/MediaSource MediaSourceResource(12fbd5180:)::SetPlaybackRate: UNIMPLEMENTED FUNCTION at /Users/jyavenard/Work/Mozilla/mozilla-central/dom/media/mediasource/MediaSourceResource.h:37
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::SetDuration: SetDuration(aDuration=0.510839, ErrorResult)
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::DurationChange: DurationChange(aNewDuration=0.510839)
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::EndOfStream: EndOfStream(aError=0)
[Main Thread]: D/MediaSource MediaSource(12fbe6040)::SetReadyState: SetReadyState(aState=2) mReadyState=1

The problem here is that remove was called with (0.5, Infinity) ; however the MFR has already decoded everything there was to decode in the sourcebuffer.
Once we've reached the end of the queued buffer.
We stay in waiting mode.

we also don't seek back to the duration as it should if currentTime was > duration.
Assignee

Updated

3 years ago
Assignee: nobody → jyavenard
Blocks: MSE
Assignee

Updated

3 years ago
See Also: → 1269830
Assignee

Updated

3 years ago
See Also: 1269830
Assignee

Updated

3 years ago
See Also: → 1269830
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 3

3 years ago
mozreview-review
Comment on attachment 8779622 [details]
Bug 1293646: [MSE] P1. Reject seeking attempt with EOS when the mediasource is ended.

https://reviewboard.mozilla.org/r/70574/#review67948

r+ with nits:

In commit description: "prior" -> "prior to".

::: dom/media/mediasource/MediaSourceDemuxer.cpp:390
(Diff revision 1)
> -      return SeekPromise::CreateAndReject(DemuxerFailureReason::WAITING_FOR_DATA,
> -                                          __func__);
> +      return SeekPromise::CreateAndReject(
> +        mManager->IsEnded() ? DemuxerFailureReason::END_OF_STREAM :
> +                              DemuxerFailureReason::WAITING_FOR_DATA, __func__);

The style is a bit strange here, I'd put ", __func__" on a separate line, left-aligned with mManager.
Attachment #8779622 - Flags: review?(gsquelart) → review+

Comment 4

3 years ago
mozreview-review
Comment on attachment 8779623 [details]
Bug 1293646: [MSE] P2. Only reject a seek request with EOS if it's passed the explicit duration.

https://reviewboard.mozilla.org/r/70576/#review67950

r+ with nits:

In commit description: "passed" -> "past".

::: dom/media/MediaFormatReader.h:14
(Diff revision 1)
>  #include "mozilla/Atomics.h"
>  #include "mozilla/Maybe.h"
> -#include "mozilla/TaskQueue.h"
>  #include "mozilla/Monitor.h"
> +#include "mozilla/StateMirroring.h"
> +#include "mozilla/TaskQueue.h"

Praise: Thank you for reordering the #includes! :-)

::: dom/media/MediaFormatReader.cpp:80
(Diff revision 1)
>    , mIsEncrypted(false)
>    , mTrackDemuxersMayBlock(false)
>    , mDemuxOnly(false)
>    , mSeekScheduled(false)
>    , mVideoFrameContainer(aVideoFrameContainer)
> +  , mExplicitDuration(mTaskQueue, Maybe<double>(), "MediaFormatReader::mExplicitDuration(Mirror)")

Tip: You can use 'Nothing()' to initialize any Maybe<T> with nothing.

::: dom/media/MediaFormatReader.cpp:1088
(Diff revision 1)
> +                        // We want to enter EOS when performing an
> +                        // internal seek only if we're attempting to seek past
> +                        // the explicit duration to avoid unwanted ended
> +                        // event to be fired.
> +                        if (self->mExplicitDuration.Ref().isSome() &&
> +                            decoder.mTimeThreshold.ref().Time() < TimeUnit::FromSeconds(self->mExplicitDuration.Ref().ref())) {

Style: Line is too long.

::: dom/media/MediaFormatReader.cpp:1742
(Diff revision 1)
>      mVideo.mSeekRequest.Complete();
>    } else {
>      mAudio.mSeekRequest.Complete();
>    }
>  
> +  // We want to enter EOS when performing aseek only if we're attempting to

Typo: 'aseek' -> 'a seek'.
Attachment #8779623 - Flags: review?(gsquelart) → review+

Comment 5

3 years ago
mozreview-review
Comment on attachment 8779623 [details]
Bug 1293646: [MSE] P2. Only reject a seek request with EOS if it's passed the explicit duration.

https://reviewboard.mozilla.org/r/70576/#review67952

::: dom/media/MediaFormatReader.cpp:259
(Diff revision 1)
>      metadata->mInfo = mInfo;
>      metadata->mTags = nullptr;
>      return MetadataPromise::CreateAndResolve(metadata, __func__);
>    }
>  
> +  mExplicitDuration.Connect(static_cast<MediaDecoder*>(mDecoder)->CanonicalExplicitDuration());

Move CanonicalExplicitDuration up the class hierarchy so we don't need this tricky static_cast.
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 8

3 years ago
Pushed by jyavenard@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/35f12e09005a
[MSE] P1. Reject seeking attempt with EOS when the mediasource is ended. r=gerald
https://hg.mozilla.org/integration/autoland/rev/5a949eb358e2
[MSE] P2. Only reject a seek request with EOS if it's passed the explicit duration. r=gerald

Comment 9

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/35f12e09005a
https://hg.mozilla.org/mozilla-central/rev/5a949eb358e2
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla51
@jya -- Can you request uplift to Aurora & Beta?  Thanks.
Flags: needinfo?(jyavenard)
Assignee

Comment 11

3 years ago
Comment on attachment 8779622 [details]
Bug 1293646: [MSE] P1. Reject seeking attempt with EOS when the mediasource is ended.

Request is for both patches.

2nd patches may need rebasing with beta.

Approval Request Comment
[Feature/regressing bug #]: MSE
[User impact if declined]: Video stalling or playback never finishing which with youtube would prevent going to the next video.
[Describe test coverage new/current, TreeHerder]: Manual test, in central.
[Risks and why]: Low. We handle seeking in the same fashion as the other mode, properly detecting when the mediasource is ended.
[String/UUID change made/needed]: none
Flags: needinfo?(jyavenard)
Attachment #8779622 - Flags: approval-mozilla-beta?
Attachment #8779622 - Flags: approval-mozilla-aurora?
Comment on attachment 8779622 [details]
Bug 1293646: [MSE] P1. Reject seeking attempt with EOS when the mediasource is ended.

Fixes a regression (which would make end-user experience when watching a youtube playlist less than ideal), Aurora50+, Beta49+
Attachment #8779622 - Flags: approval-mozilla-beta?
Attachment #8779622 - Flags: approval-mozilla-beta+
Attachment #8779622 - Flags: approval-mozilla-aurora?
Attachment #8779622 - Flags: approval-mozilla-aurora+
Attachment #8779623 - Flags: approval-mozilla-beta+
Attachment #8779623 - Flags: approval-mozilla-aurora+
Version: unspecified → 42 Branch
You need to log in before you can comment on or make changes to this bug.