1718709 - [Windows] Video freezes for a long time (20-30 seconds)

Status: VERIFIED FIXED

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

Description

[Alice0775 White]

The audio is fine, but the video freezes for a long time (20-30 seconds).

Reproducible: yes, see http://forums.mozillazine.org/viewtopic.php?f=23&t=3076330

Steps to reproduce:

1. Clear recent history everything if any
2. Open https://www.essendonfc.com.au/news/967977/injury-news-snelling-set-to-return-setback-for-phillips
3. Scroll down to Highlights | Snelling steps up in 2021 video.
4. Click play button.
5. After a 15-second ad video, the main video starts.
   However, the video will freeze after about 10 seconds or so.

Actual results:
However, the video will freeze after about 10 seconds or so.
If you let it go it'll eventually play again.

Expected results:
No freeze

Regression window:
https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=5e5c1c7e7db0d6e996ccbf56a9aa8e445bc099eb&tochange=97fb4c742d684da863aa27a32ae9d1daa8d67928

Comment 1

[Alice0775 White]

Attachment: about:support

Comment 2

[Greg ( Hank1 )]

i can reproduce the bug in this video to . https://www.essendonfc.com.au/video/968309/from-the-coach-rutten-media-conference?videoId=968309&modal=true&type=video&publishFrom=1625017859001

Comment 3

[Kestrel]

I was able to reproduce this on Windows 10 but not Ubuntu 21.04.

Comment 4

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Alastor, this looks to be regressed by bug 1692881. Do you have cycles to investigate?

Comment 5

[Alastor Wu [:alwu]]

Would anyone mind to help me to capture the debug log by using MOZ_LOG=MediaDecoder:5? Because I couldn't reproduce that on my Windows 10 and Ubuntu 20.04.
In bug 1692881, I added a new mechanism that will request to next video keyframe if the video decoding is too slow. So apparently this condition might cause a false alert? Even if we could decode the video well.
Thank you.

Comment 6

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Attachment: MediaDecoderLogOfIssue

Here's a log with MOZ_LOG=sync,timestamp,MediaDecoder:5. The other log files do not appear to have useful info, so I'm only uploading this child, let me know if you want others.

This log contains playback of the 'Highlights | Snelling steps up in 2021' video from https://www.essendonfc.com.au/news/967977/injury-news-snelling-set-to-return-setback-for-phillips and includes an ad shown before the video.

• The ad played fine, no stalls.
• The video following the ad stalled after ~7 seconds. The video remained stalled for 20+ seconds.
• The logging for the stalling video appears at around line 11266 of the log.

Comment 7

[Alice0775 White]

Attachment: log.txt.child-6.moz_log

I have attached a log file with a non-zero file size.

Elapsed time is from my watch.
Elapsed time(UTC) Incident
about 19:06:00 clicked on play button
about 19:06:10 the video image froze
about 19:06:35 the video image has resumed.

Comment 8

[Alastor Wu [:alwu]]

After some digging, I think this is Windows specific issue. Whenever the reader detects the stream id change, it would ask to recreate the new decoder. On Windows, I found that the first sample returned by the decoder would always be zero, which makes MSDM think "the decoding is too slow and we need to request for the next key frame" because that frame is apparently late comparing with current audio clock.

Comment 9

[Alastor Wu [:alwu]]

I tried other h264 videos and changed their resolution on the fly during playback, but I didn't see the decoder would return the frame with 0 timestamp after recreating the new decoder. So it seems the video provided by essendonfc is a little different.

Comment 10

[Greg ( Hank1 )]

it also does the same on a different site, https://www.news.com.au/world/coronavirus/australia/people-are-at-breaking-point-ben-fordham-calls-for-nsw-to-end-lockdown/news-story/004c3107fdb44d8def66c3f8744a3679

Comment 11

[Greg ( Hank1 )]

its works fine in Chrome/edge, just not firefox

Comment 12

[Greg ( Hank1 )]

question is, is it a fact that OpenH264 plugin is out of date in windows firefox which results in poor video? my guess linux has the most up to date openh264 plugin installed from cisco

Comment 13

[Alastor Wu [:alwu]]

No, there is nothing related with OpenH264. It's just about the first video frame that Windows platform decoder outputs is different from decoder in other platforms.

Comment 14

[Alastor Wu [:alwu]]

Attachment: Bug 1718709 - part1 : add assertions to clearly indicate the running thread for functions.

Comment 15

[Alastor Wu [:alwu]]

Attachment: Bug 1718709 - part2 : filter out the first incorrect output that MFT decoder returns.

For some h264 videos, MFT decoder will return the incorrect first output which presentation time is always zero. We also saw this issue before after calling draining [1].

If we accept that incorrect output, that will cause an out-of-order video frame get stored in our video queue and causes MDSM triggering the mechanism to request the next key frame because that out-of-order frame is way behind the current audio clock.

Therefore, we should filter that incorrect output out, and make sure we won't incorrectly discard the real first frame when this issue doesn't happen.

[1] https://stackoverflow.com/questions/39695131/windows-mft-media-foundation-transform-decoder-not-returning-proper-sample-tim

Depends on D119438

Comment 16

[Alastor Wu [:alwu]]

Attachment: Bug 1718709 - part3 : add test.

Depends on D119439

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/af0392f23e07
part1 : add assertions to clearly indicate the running thread for functions. r=bryce
https://hg.mozilla.org/integration/autoland/rev/705741f27314
part2 : filter out the first incorrect output that MFT decoder returns. r=bryce
https://hg.mozilla.org/integration/autoland/rev/1b83279868da
part3 : add test. r=bryce

Comment 18

[Dorel Luca [:dluca]]

Backed out 3 changesets (bug 1718709) for Build bustage. CLOSED TREE

Log:
https://treeherder.mozilla.org/logviewer?job_id=345151852&repo=autoland&lineNumber=17234

Push with failures:
https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&revision=1b83279868da7fdfc94ecb2301f4552c8759e26f

Backout:
https://hg.mozilla.org/integration/autoland/rev/d337892115ed05eabef76f250fc8f794d26b81d6

Comment 19

[Alastor Wu [:alwu]]

Hmm this build failure wasn't captured in my try result. Anyway, I will update that and land them again, thank you.

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2c31bb2cf0a0
part1 : add assertions to clearly indicate the running thread for functions. r=bryce
https://hg.mozilla.org/integration/autoland/rev/a3b5e41c96ae
part2 : filter out the first incorrect output that MFT decoder returns. r=bryce
https://hg.mozilla.org/integration/autoland/rev/5f7a9f34ce18
part3 : add test. r=bryce

Comment 21

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/2c31bb2cf0a0
https://hg.mozilla.org/mozilla-central/rev/a3b5e41c96ae
https://hg.mozilla.org/mozilla-central/rev/5f7a9f34ce18

Comment 22

[Gary [:streetwolf52]]

I've been freezing on videos over at msn.com and had hoped this patch would fix it. However with the patch I still freeze. The video freezes indefinitely with only the spinner moving.

Comment 23

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

(In reply to Gary [:streetwolf52] from comment #22)

I've been freezing on videos over at msn.com and had hoped this patch would fix it. However with the patch I still freeze. The video freezes indefinitely with only the spinner moving.

Is there a bug to track this? If not, could you please create one so we can track it?

Comment 24

[Gary [:streetwolf52]]

I'll do a little more research and if I find the cause is not on my end I will open up a new bug report.

Comment 25

[Gary [:streetwolf52]]

Works with a new profile. Probably an add-on or a pref. Not caused by what this patch fixed.

Comment 26

[Alice0775 White]

I have filed a new bug 1720498.

Comment 27

[Alastor Wu [:alwu]]

Comment on attachment 9230340 [details]
Bug 1718709 - part1 : add assertions to clearly indicate the running thread for functions.

Beta/Release Uplift Approval Request

• User impact if declined: Users might see some videos freeze for a certain period of time (depend on video) during playback
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: No
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: Check comment0, comment2 and comment 10. And this issue only happens on Windows.
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This patch will filter out the first video output generated by Windows video decoder, to avoid the out-of-frame video happens in the middle of playback. In the worst case, if we really filter out the frame that shouldn't be filtered out, which mean losting one more frame to users, which would just cause a very little or almost none visual defect to users.
• String changes made/needed: No

Comment 28

[Pascal Chevrel:pascalc]

Comment on attachment 9230340 [details]
Bug 1718709 - part1 : add assertions to clearly indicate the running thread for functions.

Approved for 91 beta 3, thanks.

Comment 29

[Pascal Chevrel:pascalc]

https://hg.mozilla.org/releases/mozilla-beta/rev/3aa44c30427e
https://hg.mozilla.org/releases/mozilla-beta/rev/0bbb0ec0bd12
https://hg.mozilla.org/releases/mozilla-beta/rev/711cb31006b3

Comment 30

[Pablo]

I reproduced the bug on Beta 91.0b2 ( I just checked video1,it does freeze for some seconds)

verified fix on Windows 10 64bit.

Nightly 92.0a1 (2021-07-15) build 20210715094037 : No hangs on all 3 videos.

Firefox beta 91.0b3 : No hangs on all 3 videos.

Also checked video from first comment and there was no hang using ubuntu 20 64bit and latest nightly 92.0a1 and beta 91.0b3