1699500 - Slow restyles on chat.google.com

Status: RESOLVED WORKSFORME

(Core :: CSS Parsing and Computation, defect)

Description

[Daniel Holbert [:dholbert]]

In bug 1698855, we have a profile for jank on chat.google.com, which includes some slow restyles (several that are over 1 second long, with the longest being 2.2 seconds long):
https://share.firefox.dev/3twmYB2

(Unfortunately the CPU activity is in stylo threads which I don't think (?) we have visibility into, in this profile; so may need a bit more investigation to find out what's going on.)

Comment 1

[Jonathan Kew [:jfkthame]]

1-second restyle seems pretty terrible! We should try to figure out what's causing that.

Comment 2

[Daniel Holbert [:dholbert]]

I profiled chat.google.com in Nightly with a fresh browsing profile, and I didn't get any long restyles or reflows.

Pageload (having previously logged in):
https://share.firefox.dev/38Xi9sE

Clicking into some conversations, populating some backscroll:
https://share.firefox.dev/3vHA7cp

alex_mayorga, could you give any more information about what specific actions/content seem to be associated with the poor performance here?

Comment 3

[alex_mayorga]

¡Hola Daniel!

Thanks for looking at these profiles.

I believe the issue here might be my sheer abuse of "El Goog"'s Chat.

If I used the Dev Tools Inspector correctly I happen to have 192 chat rooms currently I believe... 🙈

Here's a new profile of just loading https://chat.google.com/ and scrolling around:

https://share.firefox.dev/30Y5wt5

On normal usage I can see the icons for the rooms lists slowly refreshing from time to time, i.e. I can literally see the frames as the icons are being drawn.

Please let me know if anything further is needed from the profile or device.

¡Gracias!
Alex

Comment 4

[Emilio Cobos Álvarez (:emilio)]

Sorry for the lag getting to look at this. So the big restyles are restyling the whole page, and at least a third of the time is spent in reconstructing frames. Looking at the biggest restyle in comment 3, it is caused by nsPresContext::UpdateAfterPreferencesChanged.

Given this causes reframe, I suspect we're hitting this code path. Alex, if you still see this, do you have any software in your computer which could trigger some font changes or such?

Comment 5

[Daniel Holbert [:dholbert]]

[redirecting ni to alex_mayorga]

Comment 6

[alex_mayorga]

¡Hola Emilio, Daniel!

"El Goog" made a redesign of their chat in the recent weeks so I've captured a new profile:

https://share.firefox.dev/3umS8uL

I believe performance got a little better but still not agüesome IMHO.

I do not even know of any "software which could trigger some font changes or such" so if I have anything like that installed it would be unbeknownst to me.

Please let me know if anything further is needed from the profile or device.

¡Gracias!
Alex

Comment 7

[Daniel Holbert [:dholbert]]

Thanks! So the longest restyles that I'm seeing there are:
544ms: https://share.firefox.dev/3vqb6lA
456ms: https://share.firefox.dev/3ujoPJy

emilio, does anything jump out at you there?

Both of those seem to have their "first invalidated" blame pointing at a Node.removeChild call, and I'm not seeing any UpdateAfterPreferencesChanged calls at all (in the profile & in the backtraces of those long-restyles). So that may have just been a random/unrelated occurrence in that last profile, and might not be related to the long restyles in general.

Comment 8

[Emilio Cobos Álvarez (:emilio)]

That means that we're invalidating probably for :nth-child or such pseudo-classes here. Our invalidation there is suboptimal, though given that's only the first invalidation it's unclear if that is the only culprit. The profile looks quite different from comment 0 though, I'd note (restyles are not most of the jank at all). Most of it is JS code running and also some slow querySelector calls for selectors like [jsdata*='miQrX;ZzVSXhZpyz8\,space/AAAAzKP8_AQ;']

Comment 9

[Daniel Holbert [:dholbert]]

FWIW, I just captured a profile of chat.google.com, with a particularly-long conversation loaded (lots of long test messages), on my slowest hardware (a Microsoft Surface 3, with 8GB ram, i5-4300u chip with 2 physical cores / 4 threads), on Windows 10.

I started profiling while the site was already loaded, and then I did a shift-reload. After the load completed, I scrolled up to trigger the lazy-population-of-backscroll, and then I typed in a message (the word "reply"), and then I stopped profiling.

Profile: https://share.firefox.dev/3nTSvws

The longest restyle I encountered was 41.5ms, which is way better than the 1-second one mentioned in comment 0 and the 544ms one mentioned in comment 7. Here are the four longest restyles from my profile:

• 41.5ms: https://share.firefox.dev/3GT0D7P (around when the lazy-backscroll gets expanded)
• 31.9ms: https://share.firefox.dev/3GYUYx7 (during pageload, before the chat content has appeared)
• 21.6ms: https://share.firefox.dev/3fRpzAP (during pageload, when the "Google Workspace" splash-image progress bar is up)
• 20.0ms: https://share.firefox.dev/344Ioh0 (during pageload, when the "Google Workspace" splash-image progress bar is up)

Given the difference between these measurements vs. the ones in comment 7 & comment 0, I wonder if this has gotten better.

Alex, sorry to do this again -- would you mind retesting and seeing if this is still a problem?

(I also wonder if I'm testing the same thing, and e.g. if this depends on having a large "number of chat rooms", per the 192 that Alex mentioned in comment 3? I'm not sure if "chat rooms" there is just google-chat-conversations vs. something else.)

Comment 10

[alex_mayorga]

¡Hola Daniel!

¡Feliz 2022!

Hope these lines find you well.

I believe this issue still exists on today's Nightly, i.e. the redraw of icons for the "Spaces" is visible to my untrained eye and the fans on the laptop go crazy for quite a bit.

"Spaces" in this context is the 2nd entry seen in the next screen capture attached.

I captured a new profile over at https://share.firefox.dev/35mk23a

Hope this is useful.

Please let me know if anything further is needed from the device or profile.

¡Gracias!
Alex

Comment 11

[alex_mayorga]

Attachment: image.png

Comment 12

[Daniel Holbert [:dholbert]]

Thank you! That profile is helpful, and it confirms that slow-restyles are not an issue here anymore (at least, not in that profile, nor in the one that I recorded in comment 10.)

Your profile's longest restyle is 34ms, which (partly for my own future reference) I determined by visiting the "Marker Table" view and filtering for "Styles" and running this JS in the Web Console:

{ let longestDur = 0.0; for (let marker of filteredMarkers) { marker.dur = marker.end - marker.start; if (marker.dur > longestDur) { longestDur = marker.dur; console.log(marker)}} }

(I filed https://github.com/firefox-devtools/profiler/issues/3831 on making our profile viewer able to surface this information a bit better.)

The final logged line there is the "Styles" marker with the longest duration, and it's 34ms long. That's not too bad for a restyle associated with significant amounts of content being loaded, and it's orders of magnitude better than the ones reported above (544ms in comment 7, and 2.2 seconds (!) in the profile from comment 0).

So: it sounds like there are still perf issues to be identified here, but they're not restyle-related. Let's take this back to bug 1698855 for further diagnosis.

(Also: RE the redrawing of the "spaces" text -- it's useful to know that that's a particularly-noticable thing, but it's hard to reason about where that happens in the profile without the screenshots track. If it's possible / not-too-privacy-invasive for you to include the screenshots track, that would be helpful to sort out when that & other relevant visually-relevant-events happened in the profile.)