1452525 - Major performance regression switching to or from window with many tabs

Status: VERIFIED FIXED

(Core :: CSS Parsing and Computation, defect)

Description

[Dan Stillman]

I have a Firefox window with ~600 tabs. I'm seeing a major performance regression in the Firefox 60 beta (possibly in b10) when switching to or from that window. It happens both when switching to/from another Firefox window and to/from another program. The delay doesn't occur when just switching between two other Firefox windows with no tabs.

The profiler shows an empty 950-1000ms block (just "XREMain::XRE_main :4796 Gecko") before the 'activate' DOM event kicks in. It's suspiciously close to a full second, but that's probably a coincidence.

This happens with all extensions disabled, and goes away reliably if I switch to 59.0.2.

Tested on macOS 10.13.3.

Comment 1

[Johann Hofmann [:johannh]]

(In reply to Dan Stillman from comment #0)
> I have a Firefox window with ~600 tabs. I'm seeing a major performance
> regression in the Firefox 60 beta (possibly in b10) when switching to or
> from that window. It happens both when switching to/from another Firefox
> window and to/from another program. The delay doesn't occur when just
> switching between two other Firefox windows with no tabs.
> 
> The profiler shows an empty 950-1000ms block (just "XREMain::XRE_main :4796
> Gecko") before the 'activate' DOM event kicks in. It's suspiciously close to
> a full second, but that's probably a coincidence.
> 
> This happens with all extensions disabled, and goes away reliably if I
> switch to 59.0.2.
> 
> Tested on macOS 10.13.3.

Can you try to use mozregression (https://mozilla.github.io/mozregression/) to figure out a regression range? That would be very valuable. It allows you to pass in a profile path so that you don't have to open all 600 tabs again.

Comment 2

[Dan Stillman]

OK, I'm afraid it's https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=7f2dd59744eb4041bc5de60657d931d1a2e9859a&tochange=7a63a457c8e89edc417ea384f24102c988feb3d5. Toggling layout.css.servo.chrome.enabled to false and restarting does indeed restore the previous performance.

Comment 3

[Johann Hofmann [:johannh]]

Alright, thanks, forwarding to style people to figure out what to do with this...

Comment 4

[Johann Hofmann [:johannh]]

Oh, and it would probably be helpful to get a snapshot of the profile you were talking about. I assume you were already using it but in case you didn't know, you can upload profiles using https://perf-html.io/

Thanks!

Comment 5

[Dan Stillman]

So I think this is basically bug 1420423. For what it's worth, given the conclusion there that performance is now good enough for Fx60, while I know 600 is a crazy number of tabs, a 1-second delay whenever you switch to it does make Firefox basically unusable, and not everyone is going to understand why Firefox suddenly became so much laggier.

Comment 6

[Xidorn Quan [:xidorn] UTC+10]

Using Gecko Profiler to get a profile might be helpful, although with all the style thread it may not be that useful.

It would be great if you can set environment variable STYLO_THREADS=1 and then use the Gecko Profiler to profile.

Comment 7

[Xidorn Quan [:xidorn] UTC+10]

OK, there is no such need. I captured one myself on my nightly build on macOS: https://perfht.ml/2EwPc4D

The problem is not in restyling. Restyling isn't that bad (although it's still bad given the stats said we restyle 11000+ elements and have very few reuse), the majority of time is taken by invalidation :/

Comment 8

[Emilio Cobos Álvarez (:emilio)]

Ok, so given we only re-matched 23 elements, looks like something changed that propagated to all the other elements, doesn't it? Maybe some custom property or something?

We should also look into invalidation performance of course, probably doing it per bound element maybe?

Comment 9

[Emilio Cobos Álvarez (:emilio)]

Attachment: Lists of invalidated selectors.

That looks somewhat fishy, maybe the same sheet is referenced from multiple bindings, but there's some selectors which are repeated... We should be able to do better I'd think, I'm looking at where these come from.

Comment 10

[Emilio Cobos Álvarez (:emilio)]

Attachment: Bug 1452525: Deduplicate proto bindings, not bindings.

Review commit: https://reviewboard.mozilla.org/r/234948/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/234948/

Comment 11

[Xidorn Quan [:xidorn] UTC+10]

Comment on attachment 8966198 [details]
Bug 1452525: Deduplicate proto bindings, not bindings.

https://reviewboard.mozilla.org/r/234948/#review240582

Ah, good catch. So the deduplicate mechanism probably didn't work as expected at all :(

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e37784665179
Deduplicate proto bindings, not bindings. r=xidorn

Comment 13

[Emilio Cobos Álvarez (:emilio)]

Comment on attachment 8966198 [details]
Bug 1452525: Deduplicate proto bindings, not bindings.

Approval Request Comment
[Feature/Bug causing the regression]: stylo-chrome
[User impact if declined]: slow window activation of windows with many tabs.
[Is this code covered by automated tests?]: no
[Has the fix been verified in Nightly?]: not yet, but should be easy to.
[Needs manual test from QE? If yes, steps to reproduce]: see comment 0.
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: not risky
[Why is the change risky/not risky?]: trivial fix that avoids doing duplicate work.
[String changes made/needed]: none

Comment 14

[Florian Quèze [:florian]]

(In reply to Xidorn Quan [:xidorn] UTC+10 from comment #7)
> OK, there is no such need. I captured one myself on my nightly build on
> macOS: https://perfht.ml/2EwPc4D

This profile has a lot of samples in devtools code. If the intent wasn't to profile devtools, then it would be better to close the devtools before profiling. Or if this profile was captured without the devtools being visible, there's a bug we need to investigate.

Comment 15

[Xidorn Quan [:xidorn] UTC+10]

(In reply to Florian Quèze [:florian] from comment #14)
> (In reply to Xidorn Quan [:xidorn] UTC+10 from comment #7)
> > OK, there is no such need. I captured one myself on my nightly build on
> > macOS: https://perfht.ml/2EwPc4D
> 
> This profile has a lot of samples in devtools code. If the intent wasn't to
> profile devtools, then it would be better to close the devtools before
> profiling. Or if this profile was captured without the devtools being
> visible, there's a bug we need to investigate.

Is that a lot? I did have a devtools window open so that I can count the number of tabs easily, and I don't think that changes the issue here...

Comment 16

[Xidorn Quan [:xidorn] UTC+10]

I see what you meant. There are some short delays related to devtools, but I don't think that's related to the issue here. It is just about activate / deactivate a window with lots of tabs.

Comment 17

[Florian Quèze [:florian]]

(In reply to Xidorn Quan [:xidorn] UTC+10 from comment #15)
> (In reply to Florian Quèze [:florian] from comment #14)
> > (In reply to Xidorn Quan [:xidorn] UTC+10 from comment #7)
> > > OK, there is no such need. I captured one myself on my nightly build on
> > > macOS: https://perfht.ml/2EwPc4D
> > 
> > This profile has a lot of samples in devtools code. If the intent wasn't to
> > profile devtools, then it would be better to close the devtools before
> > profiling. Or if this profile was captured without the devtools being
> > visible, there's a bug we need to investigate.
> 
> Is that a lot?

It's most of the JS samples. But it indeed doesn't affect bug 1452622 which is still clearly visible in the profile. In this case it just makes the profile a bit confusing. In other cases where JS code plays a more significant role in what happens, the devtools noise would make the profile hard to use.

Comment 18

[Xidorn Quan [:xidorn] UTC+10]

FWIW, I would expect that the patch here to cut the time consumption here by half. Specifically, the time in invalidation should be one third of the current state (13 rules after deduplication vs. 40 rules currently).

After this change, the restyle mentioned in bug 1452622 would become significant part of the time as well, but there may still be more work to do on invalidation as well given it is still the major part of the time here.

Comment 19

[Xidorn Quan [:xidorn] UTC+10]

(Actually, since my mbp has 4C8T, the restyle time is probably shorter for me, while people with fewer cores may have longer restyle time than this. So probably optimizing restyle is also important...)

Comment 20

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/e37784665179

Comment 21

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 8966198 [details]
Bug 1452525: Deduplicate proto bindings, not bindings.

Fix an ugly performance regression with stylo-chrome. Approved for 60.0b11.

Comment 22

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/567b3f0eaddf

Comment 23

[Ryan VanderMeulen [:RyanVM]]

Backed out from Beta for bustage. Please post a rebased patch for uplift.
https://treeherder.mozilla.org/logviewer.html#?job_id=172702638&repo=mozilla-beta

https://hg.mozilla.org/releases/mozilla-beta/rev/5ee0d4fb20f40403df6ef9106d64116e5dcfe630

Comment 24

[Xidorn Quan [:xidorn] UTC+10]

Just tested the latest nightly, and it seems I underestimated the effort of that change somehow. This is the new profile: https://perfht.ml/2ExMbBn

The total invalidation time is down to ~27ms per switch (428ms in Servo_InvalidateStyleForDocStateChanges for 16 switches) vs. 489ms per switch (3912ms in that function for 8 switches), and this time I even opened slightly more tabs than last time.

The restyle becomes the only slow part now, which still takes roughly the same amount of time as last time likely due to the custom property.

Comment 25

[Xidorn Quan [:xidorn] UTC+10]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=0e1d4ed349ea42a63b558804078140aa6d5626e2

Reland in beta:
https://hg.mozilla.org/releases/mozilla-beta/rev/9ef40c935262

Comment 26

[Xidorn Quan [:xidorn] UTC+10]

(In reply to Xidorn Quan [:xidorn] UTC+10 from comment #24)
> Just tested the latest nightly, and it seems I underestimated the effort of
> that change somehow.

I mean, underestimated the effect of that change :)

Comment 27

[Oana Botisan, Desktop QA]

I managed to reproduce the bug, after I spoke with Emilio (thank you for your help), using an older version of Nightly from 2018-04-09 on macOS 10.13. The performance was indeed really bad and the whole system was lagging. 

I retested everything using the latest Nightly 61.0a1 and beta 60.0b11 on the same platform and the bug is not reproducing anymore. The switch between tabs and the switch between the browser and other windows was instant. I think this bug is fixed.