CSS animations in (embedded) SVG images consume CPU time when idle (and no longer visible/used) |
|||||||||||||
Issue descriptionWhile profiling Chrome's idle performance with procexp on Windows I've noticed that the chrome://help page does approximately 110 context switches per second. This happens even when the page is not visible and Chrome is minimized. This means that the page is preventing the CPU from going to sleep and is thus wasting power. The total CPU consumed is about .10% on my twenty-core/40-thread machine, so about 2-4% of a core. Minimizing power/CPU consumption during idle is important in order to maximize battery life. I'm marking this as Windows only for now but I suspect it also occurs on other operating systems. Note that chrome://version goes perfectly idle. See also crbug.com/612534 . I'm not sure what component/label to use - dbeam@ can you triage/redirect?
,
May 17 2016
fyi: this UI is being replaced in the upcoming Material Design settings rewrite re: which component -- we still have an "AboutBox" from the time this dialog was modal, hah! screenshot: https://tech.lds.org/forum/download/file.php?id=1802
,
May 17 2016
Okay, we should make sure that this (and other internal pages) are designed to avoid this during the rewrite. FYI, I just did some measurements using PowerMon (https://github.com/google/UIforETW/tree/master/PowerMon) which uses Intel's power estimation library to estimate how much power the CPU is drawing, sampled every two seconds. The difference after closing chrome://help is dramatic. I think the key number is Process Energy (mWh) which more more than *halves* after closing, and this is 100% reproducible. FWIW: With about://help open: CPU Frequency = 3100 MHz Processor Power (W) = 33.38 Processor Energy(J) = 67.25 Processor Energy(mWh)=18.68 IA Power (W) = 21.52 IA Energy(J) = 43.35 IA Energy(mWh)=12.04 Package Temp (C) = 48 (max is 90) With about://help closed: CPU Frequency = 3100 MHz Processor Power (W) = 15.08 Processor Energy(J) = 30.40 Processor Energy(mWh)=8.45 IA Power (W) = 5.99 IA Energy(J) = 12.07 IA Energy(mWh)=3.35 Package Temp (C) = 46 (max is 90)
,
May 17 2016
thestig@ - where are you seeing wake ups / sec in the Chrome task manager? The CPU number there is CPU time used. Since the total CPU usage of chrome://help is just a few percent of one core, and since the CPU numbers are scaled so that 100% equals total CPU power (i.e; per-core percentages are divided by number of cores/threads) the zero could hide a significant amount of CPU usage. I used "sudo perf record -e context-switches -a" to record context switches and then "sudo perf report" to display them. This groups them by process name, which is imperfect, but I could definitely see that the number of context switches attributed to Chrome dropped significantly when chrome://help is closed.
,
May 17 2016
The field exists on Mac and Linux. It's not on Windows because ProcessMetrics::GetIdleWakeupsPerSecond() is not implemented.
,
May 17 2016
,
May 17 2016
Ah - I see the column now. It's off by default but I've enabled it. Thanks for pointing that out. I'm seeing 80 wakeups per second on Linux for chrome://help. I also grabbed a trace with chrome://tracing and it shows that process waking up twice every 25 ms. It runs AnimationTimeline::serviceAnimations, then UpdateLayoutTime, then FrameView::Layout, and then UpdateLayerTree. The other wakeup just runs EventHandler::updateCursor. I see the same number of wakeups for chrome://extensions. If both are open then the wakeups seem to be coalesced as I still see just 80 for the process.
,
May 17 2016
1) if this is animation related, maybe remove the easter egg that makes Chrome spin when clicked and see if that's responsible? 2) could this instead be related to checking for channel updates?
,
May 17 2016
easter egg code: https://code.google.com/p/chromium/codesearch#chromium/src/chrome/browser/resources/help/help_page.js&sq=package:chromium&type=cs&q=help%20spin&l=185-191 https://code.google.com/p/chromium/codesearch#chromium/src/chrome/browser/resources/help/help_content.css&sq=package:chromium&type=cs&l=19-25
,
May 18 2016
The two C++ methods that are getting called on the two 40 Hz wakeups are: void SVGImageChromeClient::animationTimerFired(Timer<SVGImageChromeClient>*) void EventHandler::updateCursor() The 40 Hz wakeup on the SVG animation comes from this constant: static const double animationFrameDelay = 0.025; It looks like there are actually two sources of context switches. One only happens on official builds (presumably why you didn't see it on your Linux test) and appears to be triggered by the animating checkbox to the left of "Google Chrome is up to date." After the animation is finished the animation callback continues. This triggers 120 context switches per second on Windows. The other source is, dbeam@ suggested, from the easter egg. Once you click on that you add *another* 60 context switches per second. So, each animation triggers 60 (from their 40 Hz frame rate times magic) and the cursor updates (triggered by the animation?) provide the other 60. The good news is that a single fix to the animation engine will probably fix this as well as crbug.com/612534 and many other minor power issues.
,
May 18 2016
It appears that chrome://help is doing nothing wrong and that the root cause is somewhere in blink animation - adjusting the components appropriately. Blink team - any thoughts on this issue? I can clearly see (in ETW traces, chrome://tracing, and in the DevTools timeline that RecalculateStyle/Layout/Update Layer Tree are running at 40 Hz on chrome://help and chrome://extensions. I suspect that the issue is broader than that and probably occurs on pages in the wild as well. The problem seems to be triggered by SVG animations that have finished but continue requesting updates at every 0.025 s. The issue is made more complicated because none of the Chrome tools show what is triggering the updates, at least not in any way that I could see. I had to attach a C++ debugger in order to find that SVGImageChromeClient::animationTimerFired was part of the sequence. The chrome://extensions page appears to have two animations that run continuously. They are synchronized so the number of context switches is not affected, but the number of RecalculateStyle/Layout/Update Layer Tree is twice as great.
,
May 18 2016
Issue 612534 has been merged into this issue.
,
May 18 2016
Symptoms are virtually identical on OSX. Symptoms on Linux seem less predictable - on chrome://help the context switches often drop to zero. On chrome://extensions they seem to stay elevated indefinitely. On ChromeOS the chrome://extensions page does a very steady 80 wakeups per second, but there is not a comparable chrome://help page. I have not tested on Android or iOS.
,
May 18 2016
,
May 18 2016
This is CSS Animations in SVG images embedded as background-images (and similar) - they don't really know how to "pause" unfortunately. The resetAnimation/startAnimation (from Image) should handle this for (assuming the image is unrefed properly et.c) SMIL animation, but it doesn't know to stop the timeline for CSS animations. I think it should be possible to at least add some form of "block" to stop the pumping of frames between resetAnimation() and startAnimation(). I can try to look into that tomorrow (or, technically, today *sigh*) unless someone else feels more motivated, so I'll assign this to me for now, but feel free to grab. I figure the thing on chrome://help is throbber_small.svg from the resources? (Should probably look into grouping timers for all SVGImage instances just in case too.)
,
May 18 2016
Yes, I believe that throbber_small.svg is the one that is always running, even after it goes invisible. I'm not sure which SVG is used for the easter-egg animation mentioned in comment #9, but presumably any Chrome fix that handles throbber_small.svg will handle the easter-egg animation also. Is there some way from the chrome dev tools to identify what is triggering the repaints? If there isn't then I might open a separate issue for that. Any idea how common this problem is likely to be?
,
May 18 2016
Well, no repaints would actually be happening if things are the way I think they are - it's just a timer that gets started on first paint (of the image in question), and then if the animation is indefinite (which is the norm in these cases I'd say) it'll just be setting new timers every 25ms... I don't think there's anything in DevTools that might show that ATM. As for how common this setup is, I'd say (guess) that it's increasingly more so. (We don't have any use counters/metrics for these cases I think - maybe something worth adding...)
,
May 18 2016
fs@: if the implementation of the chrome://help spin easter egg used web animations instead of transitions, would that change anything?
,
May 19 2016
dbeam@ Even if changing the implementation on these pages would help I would (mostly) be opposed because it seems better to fix this for all cases, if possible, rather than fixing it individually. We've already got four places on two pages that would need fixing. fs@ I'll talk to the chrome://tracing people about whether this should be more understandable from within chrome://tracing or devtools - I hate these types of black boxes.
,
May 19 2016
,
May 19 2016
throbber_small.svg: https://code.google.com/p/chromium/codesearch#chromium/src/ui/webui/resources/images/throbber_small.svg&q=throbber_small.svg&sq=package:chromium&type=cs Note that CSS Animations are used in the SVG rather than SMIL.
,
May 19 2016
@dbeam: It doesn't look like the "spin easter egg" is relevant to this case (animation is not within the image but applied to the <img>. And it's not indefinite.)
,
May 19 2016
Is https://bugs.chromium.org/p/chromium/issues/detail?id=613166 an obvious duplicate? I haven't had a chance to look into it yet.
,
May 19 2016
@schenney: I don't think it is (the container around the throbber animation uses 'hidden' which translates to "display: none".)
,
May 19 2016
Attaching a smaller TC that I believe shows the series of events required to trigger this.
,
May 19 2016
oh sorry, this is already using @keyframes/animation (not transitions). my bad.
brucedawson@/fs@: of course it'd be nice to make all {transitions,animations} more efficient, I just didn't know how feasible that'd be in the short term.
btw, maybe the fill mode is affecting things?
https://developer.mozilla.org/en-US/docs/Web/CSS/animation-fill-mode
anyways, if this is an issue in blink itself and affects a wider scpoe, maybe we should title this bug something like "CSS animations consume CPU time when idle" or something along those lines rather than calling out these 2 specific pages?
,
May 19 2016
Agreed that the title should be changed - done. This bug is evolving as we understand it better.
> of course it'd be nice to make all {transitions,animations} more efficient
Nit - in this case the ask is to make a *lack* of animation more efficient.
> It doesn't look like the "spin easter egg" is relevant to this case
Are you saying that it has a different root cause? The symptoms look similar, although since the throbber timers are always running it's hard to be completely sure.
fs@ - thanks for the minimal repro.
,
May 19 2016
I added even more (search) terms to subject. > Are you saying that it has a different root cause? The "spin easter egg" runs in a different context (animation driven by "real" rAF rather than faked-timer-rAF as in SVGImage), so if it triggers wakeups et.c, the root cause is highly likely to be a different one. I should probably also mention that I don't see it as being an issue with CSS animations/transitions, but rather with how frames are generated (i.e SVGImageChromeClient::scheduleAnimation and co.) I've hacked something up that should take care of what I believe to be the core issue, but needed to be sure that I could reliably reproduce. (Hence the TC. The issue in chrome://help may not actually show if the image in question is never painted for instance.) Doing that though, I noticed that we may also be subject to GC latency (of the StyleImage wrapper for the image.) Meaning that we might not be getting sufficient signals as early as we'd like. I'll look more into that tomorrow though.
,
May 25 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/5ad4faa93d2554ffab7f72a992adbeffa8796f94 commit 5ad4faa93d2554ffab7f72a992adbeffa8796f94 Author: fs <fs@opera.com> Date: Wed May 25 22:28:41 2016 Rework timeline/frame scheduling logic for SVGImage This CL provides the SVGImage/SVGImageChromeClient complex with the capability of suspending and resuming the frame/animation tick. This gives us the mechanism required to respond to ImageObserver::shouldPauseAnimation, as well as stopping the animation timer from running after the animation has been reset (via Image::resetAnimation.) In the context of the bug referenced this means an animating SVG image will no longer cause wakeups because of (unnecessary) timer activity, saving power (and CPU time.) Implement willRenderImage() for the CrossfadeSubimageObserverProxy of CSSCrossfadeValue so that it will not (falsely) claim that it won't render its images. While doing this, try to make a decent functional split between SVGImage and the associated SVGImageChromeClient by putting all timeline/frame tick related code in the latter, while keeping code related to the actual animation/document lifecycle update in the former. BUG= 612540 Review-Url: https://codereview.chromium.org/2000483003 Cr-Commit-Position: refs/heads/master@{#396009} [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/core.gypi [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/css/CSSCrossfadeValue.cpp [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/css/CSSCrossfadeValue.h [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/svg/graphics/SVGImage.cpp [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/svg/graphics/SVGImage.h [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/svg/graphics/SVGImageChromeClient.cpp [modify] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/svg/graphics/SVGImageChromeClient.h [add] https://crrev.com/5ad4faa93d2554ffab7f72a992adbeffa8796f94/third_party/WebKit/Source/core/svg/graphics/SVGImageTest.cpp
,
May 26 2016
Removing Blink>Animation component because the issue isn't in animation code itself. The members of the animation team are in CC.
,
May 26 2016
Thank you for this fix! I've confirmed that chrome://help and chrome://extensions now go completely idle - zero context switches per second - in the normal case. I have only confirmed the fix on Windows but I assume that the fix also works on OSX and Linux. As suggested in comment #22 the easter-egg animation is a separate issue, and that issue still exists. That is, if you click on the Chrome logo on chrome://help then that process starts doing idle wake-ups (context switches) about 75 times per second. Should I open a separate bug for that?
,
May 26 2016
Opening a new bug for that SGTM.
,
May 26 2016
Will do, after I do some more analysis. Curiously I'm not seeing the easter-egg causing ongoing context switches on all of my machines. Will investigate.
,
May 27 2016
I opened crbug.com/615471 to track the remaining issue.
,
May 30 2016
Thanks. Resolving this now.
,
Jun 10 2016
,
Jun 10 2016
Issue 501143 was filed one year ago but was not root-caused at the time. It appears that it was caused by this issue which means that crrev.com/2000483003 fixed idle CPU usage for at least three chrome:// pages. Cool.
,
Jun 13 2016
Aaron Schulman did some testing with a whole-system power monitor and reported “I'm seeing a 13% total system energy reduction (with the screen dimmed) with the fix. This is with the screen at the lowest dim setting so it's a best case. 7% total energy reduction with full screen brightness.” |
|||||||||||||
►
Sign in to add a comment |
|||||||||||||
Comment 1 by thestig@chromium.org
, May 17 2016