819377 - Hang on https://www.mozilla.org/en-US/contribute/ when playing video

Status: VERIFIED FIXED

(Core :: Audio/Video, defect)

Description

[Mayank Bansal]

Attachment: about support.txt

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:20.0) Gecko/20121207 Firefox/20.0
Build ID: 20121207030741

Steps to reproduce:

1. Create a new profile
2. Go to https://www.mozilla.org/en-US/contribute/
3. Click on the video to start playing.


Actual results:

Firefox hangs. Well not exactly hangs, but I cant do any UI operations like scroll, right click , open/close tab and others.
The firefox.exe uses 100% CPU usage.


Expected results:

No hang, duh.
*************************
Can repro with HWA on and off.

Comment 1

[Mayank Bansal]

Heres a profile :

http://people.mozilla.com/~bgirard/cleopatra/#report=4b7bd37ac2371f26486486fb1c8dbbeedd483d3e&mergeUnbranched=true&invertCallback=true&selection=%255B%2522(total)%2522%252C%2522NtWaitForSingleObject%2522%252C%2522RtlpDeCommitFreeBlock%2522%252C%2522PR_EnterMonitor%2522%252C%2522mozilla%253A%253AReentrantMonitorAutoEnter%253A%253AReentrantMonitorAutoEnter(mozilla%253A%253AReentrantMonitor%2520%2526)%2522%252C%2522mozilla%253A%253AMediaDecoder%253A%253AGetStatistics()%2522%252C%2522nsHTMLMediaElement%253A%253AUpdateReadyStateForData(mozilla%253A%253AMediaDecoderOwner%253A%253ANextFrameStatus)%2522%255D

The profile shows no jank. But capturing this much profile has been extremely paining.

Comment 2

[(mostly gone) XtC4UaLL [:xtc4uall]]

Last good nightly: 2012-11-22
First bad nightly: 2012-11-23

Pushlog: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=20ec9014f220&tochange=d8e4f06198dc

=> Trunk only Regression.
=> no sure about Candidates as Regressor (there's Bug 814292 e.g.)

Comment 3

[Alice0775 White]

Regression window(m-i)
Good:
http://hg.mozilla.org/integration/mozilla-inbound/rev/dd00a3bad021
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:20.0) Gecko/20.0 Firefox/20.0 ID:20121122020052
Bad:
http://hg.mozilla.org/integration/mozilla-inbound/rev/a20b32f37e7a
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:20.0) Gecko/20.0 Firefox/20.0 ID:20121122023852
Pushlog:
http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=c6af8da7bfa3&tochange=a20b32f37e7a

Suspected:  Bug 495040

Comment 4

[Benjamin Smedberg]

This seems like an important regression!

Comment 5

[Alex Keybl [:akeybl]]

If we can't get this resolved in the next couple of weeks, we should really consider backing out bug 495040 before 20 even hits Aurora.

Comment 6

[Paul Adenot (:padenot)]

I've got a patch for this. I want to dig a little deeper before uploading it, because I have the feeling it is patching the symptoms and not the cause.

Comment 8

[Paul Adenot (:padenot)]

Attachment: Don't offset the clock by the start time of the video two times, and set the media as playing earlier. r=

This patch patches the root cause for bug 822952. The thing is, by offseting the
clock two times using the |mStartTime|, |mRemainingTime| was repeatidly
negative, then clamped to zero, causing tons of messages dispatched to the main
thread as you noted.

The other part is setting the media as playing in the state machine if it is not
marked as such, but the MediaDecoder says it is, so we can take query the audio
clock sooner and avoid having fake values.

Comment 9

[Chris Pearce [:cpearce (Not reading bugmail)]]

Comment on attachment 694325 [details] [diff] [review]
Don't offset the clock by the start time of the video two times, and set the media as playing earlier. r=

Review of attachment 694325 [details] [diff] [review]:
-----------------------------------------------------------------

Good catch Paul.

::: content/media/MediaDecoderStateMachine.cpp
@@ +2341,5 @@
>      }
>      // Current frame has already been presented, wait until it's time to
>      // present the next frame.
>      if (frame && !currentFrame) {
>        int64_t now = IsPlaying() ? clock_time : mPlayDuration;

Correct me if I'm wrong, but I think this line needs to be:

    int64_t now = IsPlaying() ? clock_time : (mPlayDuration + mStartTime);

Otherwise in the !IsPlaying() case we'll be subtracting a value which doesn't include mStartTime (|now|, which has value mPlayDuration), from a value doesn't (frame->mTime) and so meaning remainingTime will be incorrectly large and we'll have the opposite problem and end up sleeping the state machine thread for too long.

This will only matter in the case where the media has a non-zero start time, but they do exist; live streams for example.

Comment 10

[Chris Pearce [:cpearce (Not reading bugmail)]]

(In reply to Chris Pearce (:cpearce) from comment #9)
> Comment on attachment 694325 [details] [diff] [review]
> [...]
> Otherwise in the !IsPlaying() case we'll be subtracting a value which
> doesn't include mStartTime (|now|, which has value mPlayDuration), from a
> value doesn't (frame->mTime)

Oops, typo, that should have read:

Otherwise in the !IsPlaying() case we'll be subtracting a value which
doesn't include mStartTime (|now|, which has value mPlayDuration), from a
value *which does* (frame->mTime)


(i.e. VideoData::mTime timestamps include mStartTime, but |now| doesn't in the !IsPlaying() case)

Comment 11

[Paul Adenot (:padenot)]

Chris, you were right, this changeset includes the modification you propose.

https://hg.mozilla.org/integration/mozilla-inbound/rev/5add564d4546

Comment 12

[Ed Morley [:emorley]]

Push backed out for Windows pgo-only mochitest-1 timeouts in media tests, since the backout of just 1abf4c88f8f1 didn't work (see bug 793274 comment 12 for example logs):
https://hg.mozilla.org/integration/mozilla-inbound/rev/f2912b7e727a

Comment 13

[Paul Adenot (:padenot)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ea7f8d86e592

I bisected the queue on try, this patch is safe.

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/904caf7811e4

Comment 15

[Paul Adenot (:padenot)]

Comment on attachment 694325 [details] [diff] [review]
Don't offset the clock by the start time of the video two times, and set the media as playing earlier. r=

[Approval Request Comment]
Bug caused by (feature/regressing bug #): Bug 495040
User impact if declined: Freeze of the browser when playing an html5 video, the user needs to force-close it.
Testing completed (on m-c, etc.): Baked for a long time on central.
Risk to taking this patch (and alternatives if risky): Little risk, very high CPU consumption when playing video if not taken.
String or UUID changes made by this patch: none.

(requesting approval in reaction to a release-mgmt email).

Comment 16

[bhavana bajaj [:bajaj]]

Comment on attachment 694325 [details] [diff] [review]
Don't offset the clock by the start time of the video two times, and set the media as playing earlier. r=

Approving on aurora considering it is Fx20 regression and has had good bale-time on m-c.

Adding qawanted,verifyme to help with QA verification.

Comment 17

[bhavana bajaj [:bajaj]]

(In reply to Paul Adenot (:padenot) from comment #15)
> Comment on attachment 694325 [details] [diff] [review]
> Don't offset the clock by the start time of the video two times, and set the
> media as playing earlier. r=
> 
> [Approval Request Comment]
> Bug caused by (feature/regressing bug #): Bug 495040
> User impact if declined: Freeze of the browser when playing an html5 video,
> the user needs to force-close it.
> Testing completed (on m-c, etc.): Baked for a long time on central.
> Risk to taking this patch (and alternatives if risky): Little risk, very
> high CPU consumption when playing video if not taken.
> String or UUID changes made by this patch: none.
> 
> (requesting approval in reaction to a release-mgmt email).

Paul, please keep a look out for any regression's from this uplift..In case we find regressions due to this & are not resolved before Fx20 hits beta we should consider backing out Bug 495040.

Comment 18

[Paul Adenot (:padenot)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/f0459f2356bc

Comment 19

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

I backed this out for Windows bustage: https://hg.mozilla.org/releases/mozilla-aurora/rev/de299ce2b2c1

Comment 20

[Paul Adenot (:padenot)]

Relanded with a fix.

https://hg.mozilla.org/releases/mozilla-aurora/rev/8d1c80a56d00

Comment 21

[Manuela Muntean [Away]]

Verified with Firefox 20 beta 1 on: Mac OSX 10.7.5, Ubuntu 12.04 32-bit, Windows 7 32-bit.

Build ID: 20130220104816

Comment 22

[Bogdan Maris, Desktop Test Engineering]

Mozilla/5.0 (Windows NT 6.1; WOW64; rv:21.0) Gecko/20100101 Firefox/21.0
Mozilla/5.0 (X11; Linux x86_64; rv:21.0) Gecko/20100101 Firefox/21.0

On https://www.mozilla.org/en-US/contribute/ there is no video now so I tested the video from http://careers.mozilla.org/en-US/ and the issue is not reproducible so it should be verified fixed. If the video is not similar with the one given in comment 0 then this is not verified as fixed.

Comment 23

[Bogdan Maris, Desktop Test Engineering]

Tested on Firefox 21 beta 3 (buildID: 20130416200523).

Comment 24

[Alice0775 White]

The following url is reproducible the problem in the bad build of comment#2 and comment#3

http://www.mozilla.org/en-US/firefox/23.0a1/firstrun/

Comment 25

[Bogdan Maris, Desktop Test Engineering]

(In reply to Alice0775 White from comment #24)
> The following url is reproducible the problem in the bad build of comment#2
> and comment#3
> 
> http://www.mozilla.org/en-US/firefox/23.0a1/firstrun/

Verified as fixed on Firefox 21 beta 3 (buildID: 20130416200523) using this url.