Closed Bug 1699039 Opened 4 years ago Closed 4 years ago

Inspector Animation panel causes a high CPU load (80% for http://www.esprit.de) due to updates of the timer value

Categories

(DevTools :: Inspector: Animations, defect, P3)

defect

Tracking

(firefox89 fixed)

RESOLVED FIXED
89 Branch
Tracking Status
firefox89 --- fixed

People

(Reporter: whimboo, Assigned: daisuke)

References

(Blocks 3 open bugs)

Details

(Keywords: memory-footprint, power)

Attachments

(3 files, 1 obsolete file)

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:88.0) Gecko/20100101 Firefox/88.0 ID:20210312033752

Especially with a lot of animations listed on that panel the DevTools panel is using a lot of CPU for just updating / rendering the internal animations and timer output. Most of it goes into the main thread of the parent process.

Steps:

  1. Open https://www.esprit.de/herrenmode/bekleidung/pullover-strickjacken
  2. Open DevTools and select the inspector pane
  3. Select the Animations panel

Here a recorded profile: https://share.firefox.dev/3eOmphG

Also there are massive memory allocations that quickly increases the memory of the parent process, and which doesn't seem to get freed (didn't test long enough). So maybe this also contributes to the high CPU load.

CPU of the Web Content process spikes for me above 100% even without the dev tools open, main process goes up to 40%.
Here is a profile: https://share.firefox.dev/3bQyn8J

Priority: -- → P2

I missed to add that the general CPU load issue with Firefox on that website is covered by bug 1698445. But DevTools adds a good amount of extra load on top of it.

Ah, cool. Maybe Emilio can make use of that profile then ;)

As I think this issue was fixed by bug 1699040, will mark as duplicate.
If not fixed yet, please let me know.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE

No, it's not fixed by Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:89.0) Gecko/20100101 Firefox/89.0 ID:20210329214331.

Just opening the devtools panel still causes a CPU load > 100%.

Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---

Here a profile: https://share.firefox.dev/3fpDlLP

I suspect that this is the rendering for the animation timer, which gets updated in really short time intervals. Even if we run with 60Hz compositing it would mean 16.6ms should be enough, and I feel it's done more often now, or?

It's based on a timer using requestAnimationFrame, so it's fired every 16.6ms at most.
https://searchfox.org/mozilla-central/rev/74d0efd1107a26f178b108b6a18a179e9b06547c/devtools/client/inspector/animation/current-time-timer.js#63

But updating the state of all the animations in the page still takes time.

Every frame, we refresh at least 2 react components: the CurrentTimeScrubber and the CurrentTimeLabel.

Commenting out their current-time-timer listener (CurrentTimeScrubber & CurrentTimeLabel) helps to keep the CPU at regular levels.

Both components are really basic, but I guess involving React components in a requestAnimationFrame loop is not working out.
In theory this also means that this affects any page which has animations continuously playing, regardless of the number of animations.

Attached file 500-animations.html (deleted) —

Thank you very much for letting me know, Henrik!
Will the CPU be 100% all the time? Or only when opening the animation inspector or reloading the site?
If the animation of scrubber and time label lead to this issue, could you please check with the attached file having 500 animations?
If there is no problem, the issue may relate to the https://www.esprit.de/ site?

And also, thank you very much for taking a look at this, Julian!

I also get 100% CPU with your test page, only when the animation inspector is open. And commenting out the rendering of the components I mentioned also fixes the issue.

Thank you very much, Julian!
So, do you think we should use setTimeout? or something else instead of requestAnimationFrame?

Attached file simple-animation.html (deleted) —

And if rendering the scrubber and time label leads to this issue, can we reproduce CPU 100% even one animation of the attachment?

Thanks for the additional test page!

With 500 animations but no animation inspector:

  • parent process: 30% CPU
  • content process: 70% CPU

With 500 animations and animation inspector:

  • parent process: 95% CPU
  • content process: 70% CPU

With 1 animation but no animation inspector:

  • parent process: 15% CPU
  • content process: 1% CPU

With 1 animation and animation inspector:

  • parent process: 75% CPU
  • content process: 1% CPU

So in both cases, I have around 60% CPU usage increase linked to the animation inspector.
I had the feeling this would be the case, but it's good to have confirmation: the issue impacts any website which has an ongoing animation.

We can consider the issue from several angles:

  • we render too quickly, rAF is too fast. => maybe try to render only once every 100ms (but it will look less smooth)
  • rAF should be fine but React is too slow to be called every 16 ms. => instead of re-rendering the 2 components, try to update textContent, style, etc...
  • rAF should be fine, react should be fine, but the engine struggles with the changes we do every 16ms. Is there an issue with the layout we are using?

We could just go with the first option, slow down the rendering. But I think it would be nice to investigate and understand if React is the issue, or if our layout (and maybe the engine) could be improved.

Thank you very much for your detailed investigation and suggestions, Julian!
I will try your suggestions and find a good way!

Maybe also check the following:

  1. Figure out which of the both renderings is causing the problem. Maybe not both are affected? At least from my last profile I can see that a lot of time goes into onCurrentTimeTimerUpdated.
  2. Slowing down rendering of the time should be less noticeable as doing it for the animation.
  3. Work with someone from the DOM/GFX team to further reduce overhead.

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #15)

Maybe also check the following:

  1. Figure out which of the both renderings is causing the problem. Maybe not both are affected? At least from my last profile I can see that a lot of time goes into onCurrentTimeTimerUpdated.

I didn't explicitly say it, but when I wrote comment 8, I tested each independantly. They are both roughly responsible for 50% of additional load, no clear difference.

  1. Slowing down rendering of the time should be less noticeable as doing it for the animation.

Good point. We could land a first improvement only slowing down the text. As I said, both are equally responsible for the issue so that should already give us a nice improvemnt.

  1. Work with someone from the DOM/GFX team to further reduce overhead.

Definitely, if it's not React and it's layout/engine related, we'll need to coordinate.

Hi! I tried to reduce the frequency of rendering using setTimeout(100).
The movie is https://i.gyazo.com/b9c11cd74831bbd5848e3b93616602b1.mp4
It looks a bit awkward. And, used CPU power about 45% against 80% (original) on my local env.
Next, I will investigate the React component.

I tried to make these components into uncontrolled components.
CPU power about 60 - 70% against 70 - 80% (original) on my local env.
Julian, when you have time, could you test the above patch??

Flags: needinfo?(jdescottes)

Updated measures with your patch:

With 500 animations but no animation inspector:

  • parent process: 30% CPU
  • content process: 70% CPU

With 500 animations and animation inspector:

  • parent process: 70% CPU (was 95% CPU)
  • content process: 70% CPU

With 1 animation but no animation inspector:

  • parent process: 15% CPU
  • content process: 1% CPU

With 1 animation and animation inspector:

  • parent process: 45% CPU (was 75% CPU)
  • content process: 1% CPU

The animation inspector still increases visibly the CPU usage, but in the range of +30-40% CPU increase, whereas it was +60-65% without the patch. All this improvement is purely linked to React, right?

Flags: needinfo?(jdescottes)

Thank you very much, Julian!
Yes. Until now, we have updated the scrubber and the label via setState() of React mechanism.
Then, in this change, I change the raw doms instead of that.
So, do you think we can push this patch for now?

Ah, and it seems that we may avoid rendering if the scrubber is out of the displayable area.

Yes, we should move forward with this, and probably file a follow up to keep investigating. Do you think we could somehow use a CSS animation for the scrubber's position instead of using JS?

Okay, thank you so much!

(In reply to Julian Descottes [:jdescottes] from comment #23)

Do you think we could somehow use a CSS animation for the scrubber's position instead of using JS?

The scrubber is draggable. So, if dragging, need to control by JS I think. Otherwise, we may be able to use CSS Animations or Web Animations, it will be a bit complex.

Assignee: nobody → daisuke
Status: REOPENED → ASSIGNED
Attachment #9213524 - Attachment description: WIP: Bug 1699039: Make components refering to time to uncontrolled component. → Bug 1699039: Make components refering to time to uncontrolled component.r?jdescottes
Severity: -- → S3
Priority: P2 → P3
Attachment #9213025 - Attachment is obsolete: true
Pushed by dakatsuka.birchill@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/41f00813422a Make components refering to time to uncontrolled component.r=jdescottes
Status: ASSIGNED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Target Milestone: --- → 89 Branch

Only a partial fix landed and the CPU load is still very high. As such reopening for further discussion.

Status: RESOLVED → REOPENED
Resolution: FIXED → ---

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #27)

Only a partial fix landed and the CPU load is still very high. As such reopening for further discussion.

Can we file follow up bugs instead? A fix landed for this, reopening bugs and landing other patches for the same record makes things harder to track.

Hi Henrik,

I filed a meta for animation inspector issues at https://bugzilla.mozilla.org/show_bug.cgi?id=1704734
I would prefer to close this bug since a patch already landed. Is this fine with you?

Flags: needinfo?(hskupin)

Sure, will file in a moment. In this case lets make this bug for the timer value only. Feel free to adjust the summary if it doesn't fit.

Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Summary: Inspector Animation panel causes a high CPU load (80% for http://www.esprit.de) → Inspector Animation panel causes a high CPU load (80% for http://www.esprit.de) due to updates of the timer value
Blocks: 1704745
Flags: needinfo?(hskupin)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: