1313955 - Paused videos in background tabs change time position slightly when the tab is selected

Status: VERIFIED FIXED

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

Description

[Caspy7]

STR:
1) Open a youtube video such as this https://youtu.be/WqJS_FqZNJ0
2) Pause the video
3) Open a new tab or switch to another tab in the same window
4) Wait for 15 seconds and switch back

The image will usually change slightly as though it advanced either forward or backward a frame or more

I've tested in a fresh profile and still saw the issue.
I'm on Windows 10, 51.0a2 (2016-10-29) (64-bit)

Let me know if you need more info.
Currently receiving webm on youtube.

Comment 1

[u480271]

I've looked at this and it appears to be a problem with recovering from dormant mode./

Comment 2

[u480271]

Attachment: MediaDecoder logging of dormant mode

Logging the process for entering and exiting dormant mode.

Comment 3

[u480271]

Relevant parts of the log:
[MediaPlayback #3]: D/MediaDecoder Decoder=7f38190c4800 StopPlayback()
[MediaPlayback #3]: V/MediaDecoder VideoSink=7f381915d0e0  playing (1) -> (0)
[MediaPlayback #3]: V/MediaDecoder VideoSink=7f381915d0e0 playing video frame 40673000 (id=418) (vq-queued=11)

Pause video and video sink is trimmed to 1 frame beginning at 40673000.

[MediaPlayback #5]: D/MediaDecoder [AccurateSeekTask] Decoder=7f38190c4800 DropVideoUpToSeekTarget() frame [37370000, 37403000]
[MediaPlayback #5]: D/MediaDecoder [AccurateSeekTask] Decoder=7f38190c4800 DropVideoUpToSeekTarget() pop video frame [37370000, 37403000] target=40636898

Start recovery and seek to 40636898. Hold on that's before the time of the frame in the VideoSink... [snip]

[MediaPlayback #7]: D/MediaDecoder [AccurateSeekTask] Decoder=7f38190c4800 DropVideoUpToSeekTarget() frame [40607000, 40640000]
[MediaPlayback #7]: D/MediaDecoder [AccurateSeekTask] Decoder=7f38190c4800 DropVideoUpToSeekTarget() found video frame [40636898, 40640000] containing target=40636898
[MediaPlayback #7]: D/MediaDecoder Decoder=7f38190c4800 Changed state from SEEKING (to 40636898) to DECODING
[MediaPlayback #7]: D/MediaDecoder Decoder=7f38190c4800 Seek completed, mCurrentPosition=40636898
[MediaPlayback #7]: V/MediaDecoder VideoSink=7f381915d0e0 playing video frame 40636898 (id=423) (vq-queued=1)

Recovered and seek to frame beginning 40607000. But that's the wrong frame and doesn't match what's in the VideoSink. Depending on how far the seek is from the last keyframe, it's possible to see the frame before switching to dormant before the decode presents the "new" frame that's a couple of frames in the past.

Comment 4

[u480271]

Should seek to mMediaSink->GetPosition() to match what the frame that VideoSink kept.

Comment 5

[u480271]

Attachment: Bug 1313955 - Dormant recovery seek uses wrong time.

Dormant mode is setting recovery seek to MDSM::mCurrentPosition which
doesn't match what MediaSink position which is used to leave the last
frame in the image container.

Switch to using mMediaSink->GetPosition for dormant recovery seek
target.

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

Comment 6

[u480271]

Attachment: Aurora uplift version.

MozReview-Commit-ID: KrBvUNP10ip

Comment 7

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

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

https://reviewboard.mozilla.org/r/89680/#review89096

Comment 8

[u480271]

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

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

Comment 9

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

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

https://reviewboard.mozilla.org/r/89680/#review89136

::: dom/media/MediaDecoderStateMachine.cpp:1152
(Diff revision 2)
>    if (!aDormant) {
>      return true;
>    }
>    SeekJob seekJob;
> -  seekJob.mTarget = SeekTarget(mMaster->mCurrentPosition,
> +  int64_t seekTargetTime =
> +    mMaster->mMediaSink->IsStarted() ? mMaster->mMediaSink->GetPosition() :

mMaster->GetClock() : mMaster->GetMediaTime();

Comment 10

[u480271]

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

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

Comment 11

[u480271]

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

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

Comment 12

[u480271]

Comment on attachment 8806184 [details]
Bug 1313955 - Dormant recovery seek uses wrong time.

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

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a8211df712a7
Dormant recovery seek uses wrong time. r=jwwang

Comment 14

[u480271]

Attachment: Aurora uplift version r?jwwang

MozReview-Commit-ID: 4ZPOU3aPg8b

Comment 15

[u480271]

Anthony, do we care about requesting uplift for this?

Comment 16

[Anthony Jones (:ajones, :kentuckyfriedtakahe, :k17e)]

(In reply to Dan Glastonbury :kamidphish from comment #15)
> Anthony, do we care about requesting uplift for this?

Given that you have a patch, we can let RelMan decide if they want to take it.

Comment 17

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/a8211df712a7

Comment 18

[Cristian Comorasu, QA [:ccomorasu], Releae Desktop QA - Please contact [e-mail]]

I reproduced this issue using Fx 52.0a1, build ID: 20161030030204, on Windows 10 x64.
I can confirm this issue is fixes, I verified using Fx 52.0b4, build ID: 20170206101855, on Windows 10 x64.

Cheers!