Multiple video painting regressions on Surface Pro in power save mode over last 2 months

RESOLVED FIXED in Firefox 22

Status

()

Core
Audio/Video
RESOLVED FIXED
4 years ago
3 years ago

People

(Reporter: cpearce, Assigned: cpearce)

Tracking

Trunk
mozilla23
x86_64
Windows 8
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox21 unaffected, firefox22+ fixed, firefox23+ fixed)

Details

(URL)

Attachments

(1 attachment)

(Assignee)

Description

4 years ago
I've noticed that the <video> on the Surface Pro has gotten gradually worse over the past few weeks. I've been testing with the Surface running in "Power Saver" power plan. Possibly this manifest on other devices too.

I made a page to measure video painting performance:
http://people.mozilla.org/~cpearce/bbb480.html

This measures the percentage of images set on the ImageContainer with ImageContaier::SetCurrentImage() ("presented images") that actually make it onto the screen before the next ImageContainer::SetCurrentImage() ("painted").

By this measure our painting performance has decreased over the past 2 months, and video looks noticeably worse.

Some data points from my Nightly builds on the test page on the Surface Pro:

2013-03-02 - 99% of presented frames are painted
2013-04-01 - 90% of presented frames are painted
2013-04-07 - 76% of presented frames are painted
2013-04-28 - 66% of presented frames are painted

Note: these tests are on builds without DXVA, that hasn't landed yet, i.e. software decoding H.264 on Windows.

I'm assuming this is a bug in Layers, since there's been no significant change to the video decoder code in the last two months.

Jim Mathies also noticed this. He was measuring video painting by counting MozAfterPaints, and he counted 148 paints/second, which seems awfully high and sounds to me like it could be related.

STR:
1. Get yourself a Surface Pro.
2. Set Surface to run in "Power Saver" power plan.
3. Load http://people.mozilla.org/~cpearce/bbb480.html
4. Press "Begin" button on page. Video will enter fullscreen and play.
5. Once video playback ends (it's 34 seconds long, ends in a blank white frame) press ESC to exit fullscreen.
6. Observe the "Painted X% of presented frames." text on the page. That's the percentage of frames that the video decoding infrastructure sent to the ImageContainer to paint that made it onto the screen before the video decoder's next call to ImageContainer::SetCurrentImage(). i.e. the percentage of frames dropped in the rendering pipeline is 100-X.

I will work to narrow down those regression ranges.
(Assignee)

Comment 1

4 years ago
Also I should point out that the painting regression still happens in DXVA builds.

Comment 2

4 years ago
The layers refactoring landed during this time period, see bug 852734.
(In reply to Jim Mathies [:jimm] from comment #2)
> The layers refactoring landed during this time period, see bug 852734.

Seems that we were in downward trend before then; layers refactoring landed April 10, at which point we already had a 24% drop in performance.
(Assignee)

Comment 4

4 years ago
How did you measure the 24% drop in performance Milan?

Also, when I tested again yesterday afternoon I couldn't reproduce the results I reported in comment 0. But when I unplugged my Surface so that I was running only on battery, after a while I started to see perf begin to degrade as the battery drained. IIRC my Surface was still charing (i.e. not 100% charged) when I measured the regression results I reported in comment 0. So I'm not sure if this is actually a regression, or if it's a quirk of this device when on battery or not fully charged or what.
Right - I was just commenting based on comment 0.  It goes from 76% before layers refactoring, then to 66% after layers refactoring (and who knows what else).  I just meant to say that it doesn't appear all the bad things are due to April 10th landing.  However, it sounds like maybe we need to remeasure, keeping the rest of the parameters fixed (e.g., always plugged in)?
(Assignee)

Comment 6

4 years ago
OK, I've narrowed this regression down, it started at this changeset:

d4a5a1e1e8e9   Avi Halachmi נBug 590422: Remove delay line filter from timer thread. r=bz

I was testing on the Surface Pro in power save mode, plugged in with battery fully charged.

Build of offending revision:
http://people.mozilla.org/~cpearce/firefox-22.0a1.en-US.win32.d4a5a1e1e8e9.zip

Build of previous good revision:
http://people.mozilla.org/~cpearce/firefox-22.0a1.en-US.win32.04e088286219.zip

(You may need to install the VS2012 runtime redist to run those builds).

There's a lot of discussion in bug 590422, so I will comment there regarding this regression.
Blocks: 799315
Depends on: 590422

Comment 7

4 years ago
(In reply to Chris Pearce (:cpearce) from comment #6)
> OK, I've narrowed this regression down, it started at this changeset:
> 
> d4a5a1e1e8e9   Avi Halachmi נBug 590422: Remove delay line filter from timer
> thread. r=bz
> ...
> There's a lot of discussion in bug 590422, so I will comment there regarding
> this regression.

See bug 590422 comment 55.
TL;DR:
- Possibly a regression of bug 822490, and could be fixed with bug 836869.
- Possible indeed a regression of bug 590422, at which case we might need to enable the filter when QPC is disabled, instead of ripping it out completely.
- Possibly some explicit or implicit compensation system for irregular timers within the video playback code, which backfires once the timers are more regular (after landing bug 590422).

Suggestions, try both at scenarios where video works well, and at those where it regressed:
- Report results of performance_now Mochitest3 runs.
- Report results of visiting http://people.mozilla.org/~wmccloskey/example1.html .

Comment 8

4 years ago
(In reply to Avi Halachmi (:avih) from comment #7)
> - Report results of visiting
> http://people.mozilla.org/~wmccloskey/example1.html .

That page doesn't seem to work with today's nightly. A similar one - which also adds a benchmark option - does work in current nightly: http://people.mozilla.org/~npierron/snappy-bench/
BTW, I've just landed bug 836869 on m-i.
(Assignee)

Comment 10

4 years ago
(In reply to Honza Bambas (:mayhemer) from comment #9)
> BTW, I've just landed bug 836869 on m-i.

I'll try building and testing inbound.
(Assignee)

Comment 11

4 years ago
Bug 836869 didn't solve the problem. However enabling high precision timers on Windows while we're playing video by calling timeBeginPeriod(1)/timeEndPeriod(1) did solve the problem. 

I'll make a patch to add these calls to the MediaDecoderStateMachine, and we can take that on Aurora and m-c.
(Assignee)

Comment 12

4 years ago
We'll fix this in content/media, so moving to video component.
Assignee: nobody → cpearce
Component: Graphics: Layers → Video/Audio
(Assignee)

Comment 13

4 years ago
Created attachment 744356 [details] [diff] [review]
Patch: Enable high precision timers on Windows while playing video

Enable high precision timers on Windows while we're playing video. This stops us dropping approximately 15% of frames on the Surface Pro while playing video, a regression since bug 590422 landed on 15 March this year.
Attachment #744356 - Flags: review?(kinetik)
Attachment #744356 - Flags: feedback?(vladimir)
Comment on attachment 744356 [details] [diff] [review]
Patch: Enable high precision timers on Windows while playing video

Yup, perfect.  Part of me wonders if we want a generic "enable/disable high precision timers" call that can be implemented per-platform, but windows is the only one that I can think of where it matters or where we have something to call.
Attachment #744356 - Flags: feedback?(vladimir) → feedback+
(In reply to Chris Pearce (:cpearce) from comment #0)
> Some data points from my Nightly builds on the test page on the Surface Pro:
> 
> 2013-03-02 - 99% of presented frames are painted
> 2013-04-01 - 90% of presented frames are painted
> 2013-04-07 - 76% of presented frames are painted
> 2013-04-28 - 66% of presented frames are painted

(In reply to Chris Pearce (:cpearce) from comment #13)
> Enable high precision timers on Windows while we're playing video. This
> stops us dropping approximately 15% of frames on the Surface Pro while
> playing video, a regression since bug 590422 landed on 15 March this year.

So do the high resolution timers fix everything? or just some of these multiple regressions? What percentage of the frames are painted now?
(Assignee)

Comment 16

4 years ago
I built yesterday's inbound with my high resolution timers patch, and 100% of frames were painted.
Attachment #744356 - Flags: review?(kinetik) → review+
(Assignee)

Comment 17

4 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/9b75691bf636

We'll need this on Aurora too.
(Assignee)

Comment 18

4 years ago
Comment on attachment 744356 [details] [diff] [review]
Patch: Enable high precision timers on Windows while playing video

[Approval Request Comment]
Bug caused by (feature/regressing bug #): HTML5 video on windows, regressed by bug 590422
User impact if declined: Video will drop lots of frames and look crappy on some Windows machines, including the Surface Pro.
Testing completed (on m-c, etc.): Tested on the machines I have here. This patch just landed on m-i.
Risk to taking this patch (and alternatives if risky):  Very low risk, and it's trivial to back out if we find problems.
String or IDL/UUID changes made by this patch: None.
Attachment #744356 - Flags: approval-mozilla-aurora?
https://hg.mozilla.org/mozilla-central/rev/9b75691bf636
Status: NEW → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla23

Updated

4 years ago
status-firefox21: --- → unaffected
status-firefox22: --- → affected
status-firefox23: --- → fixed
tracking-firefox22: --- → +
tracking-firefox23: --- → +

Updated

4 years ago
Attachment #744356 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+

Comment 20

4 years ago
Setting 1ms is always a risk, so here are quick power numbers:

Using http://www.youtube.com/watch?v=tgbNymZ7vqY at 1080p, windowed, forcing h.264, Win8, balanced mode on AC power.

bug 847267 patches alone : 9.12 Watts (Package Power)
bug 847267 + this patch  : 9.25 Watts 
idle                     : 7.75 Watts

Measured with Intel Power Gadget http://software.intel.com/en-us/articles/intel-power-gadget
(In reply to Joe Olivas from comment #20)
> Setting 1ms is always a risk, so here are quick power numbers:
> bug 847267 patches alone : 9.12 Watts (Package Power)
> bug 847267 + this patch  : 9.25 Watts 
> idle                     : 7.75 Watts

Considering that for 1% increase in power we get quite a bit more than 1% increase in painted frames (if this video playback is similar to the one from comment 0), not only does it seem to be worth the cause, we also get better CPU utilization with this patch. Though, depending on implementation/drivers, this possibly doesn't take into account extra GPU usage required to present more frames (but the intel power tool could definitely take GPU usage into account).

Also, seeing that enabling high-res timers fixes the issue, I don't think it fixes the regression from bug 590422, as that bug never changed this aspect. Is this something we wish to explore more?
(Assignee)

Comment 22

4 years ago
https://hg.mozilla.org/releases/mozilla-aurora/rev/82b5a8160005
(Assignee)

Comment 23

4 years ago
(In reply to Avi Halachmi (:avih) from comment #21)
> Also, seeing that enabling high-res timers fixes the issue, I don't think it
> fixes the regression from bug 590422, as that bug never changed this aspect.
> Is this something we wish to explore more?

If it's possible that we can reduce power usage by doing something smarter, we should investigate. Probably not ultra high priority at the moment, but we should get around to it sooner rather than later.

Comment 24

4 years ago
Fixed cross compiling for Windows on case sensitive hosts (mingw fix):

https://hg.mozilla.org/integration/mozilla-inbound/rev/03873ae2cede

Updated

4 years ago
status-firefox22: affected → fixed
https://hg.mozilla.org/mozilla-central/rev/03873ae2cede
Depends on: 869285

Updated

4 years ago
QA Contact: jbecerra
Keywords: verifyme
Using the latest nightly on a Surface Pro, I followed the steps in comment #0 and comment #8 and here are the numbers shown after visiting the pages referenced:

100.12224938875305

Frame Average: 17.014133333333334
Frame Variance: 2.922733582222179
Score: 49.72777886573912

Does that look like the expected results?
Flags: needinfo?(cpearce)
(Assignee)

Comment 27

4 years ago
Juan: I never tested with the steps in comment 8, so I don't know what to expect there. I only tested with the steps in comment 0. You should get results like "100%" or "99%" when the bug is fixed (it looks like you did based on your comment).
Flags: needinfo?(cpearce)
BTW, please read http://www.belshe.com/2010/06/04/chrome-cranking-up-the-clock/ for background on timeBeginPeriod, in particular with laptop battery use.  And as we move towards eliminating flash, it will have more impact (at least on < win8).

Also: http://randomascii.wordpress.com/2013/07/08/windows-timer-resolution-megawatts-wasted/#more-1285
and https://code.google.com/p/chromium/issues/detail?id=153139 for it regressing in Chrome

It can also slow your machine down by 2-5% when it isn't needed.  Apparently we did video playback smoothly before without 1ms timing (using the delayline code that's been disabled/removed now).

I'll need to look at WebRTC (since the Chrome people flagged it has unbalanced timeBeginPeriod() in clock.cc)
The timeBeginPeriod in webrtc if balanced with timeEndPeriod, at least in the version we're using
Question: if we used the delayline code still, could we avoid this timeBeginPeriod?  Could we use an alternate timer with-delayline for video playback and avoid it?  And is it needed on desktops (assuming nothing else has forced the system into 1ms timing)?
(In reply to Randell Jesup [:jesup] from comment #30)
> Question: if we used the delayline code still, could we avoid this
> timeBeginPeriod?  Could we use an alternate timer with-delayline for video
> playback and avoid it?  And is it needed on desktops (assuming nothing else
> has forced the system into 1ms timing)?

bz could probably provide some insight as well. Both were very much in favor of ripping out the timer filter completely.
Flags: needinfo?(vladimir)
I'll admit to not understanding how the delay filter stuff could have made this better.  I would love to see a log of exactly when the video-related timers are scheduled and when they fire both with and without the timer filter stuff.
Flags: needinfo?(vladimir)
A bit out of scope of this specific issue, I wonder if next time we want to remove some system, we should instead just noop/pref-opt-in the code (if it's relatively simple) instead of deleting the code. We could then leave an open bug to also remove the code once we're satisfied with the results.

First system which comes to my mind wrt to the above is the one from bug 880036.
mass remove verifyme requests greater than 4 months old
Keywords: verifyme
You need to log in before you can comment on or make changes to this bug.