Closed Bug 1382311 Opened 6 years ago Closed 6 years ago

obama wikipedia page has slow restyles 5-10 times during pageload

Categories

(Core :: CSS Parsing and Computation, enhancement, P1)

Product:
Core
Component:
CSS Parsing and Computation
Type:
enhancement

Tracking

()

Status:
RESOLVED FIXED
Project Flags:
Performance Impact low

People

(Reporter: bholley, Unassigned)

References

Details

Attachments

(1 file)

saved profile of Chrome 61 dev loading Obama Wikipedia page
8.30 MB, application/json
Details 
I had hoped bug 1373537 would take care of this, but the problem seems to remain.

This is not stylo-specific, and in fact stylo seems to do fewer full-document styles than gecko does.

URL: https://en.wikipedia.org/wiki/Barack_Obama

Gecko profile: https://perfht.ml/2vjUZat
Stylo profile: https://perfht.ml/2vjOjcs

We should figure out what's going on, and see if there's some way we can avoid recomputing everything, or alternatively, suggest a fix to wikipedia to stop doing whatever dumb thing they're doing.
Note that things get significantly worse when ABP is enabled. I filed bug 1382319 about that.
heycam, maybe you could take a look here?  (to get an idea of why we're restyling so many times when loading wikipedia
Flags: needinfo?(cam)
Whiteboard: [qf] → [qf:p1]
I'll just take a quick initial look, actually. My observations from the Gecko profile in comment 0:
 - The last 8 blue marker-bars are all for restyles, and they're all on the order of 75-100ms long.

 - Those restyles are all during refresh driver ticks. So these aren't synchronous style flushes or anything like that -- rather, it's that styles are changing between (or on) refresh driver ticks, in a way that is expensive for us to flush when the tick happens.

 - In each case, there is a very short "scripts" marker before the restyle (as part of the refresh driver tick), and that script is mostly a call to a function called "addEmbeddedCSS".  Here's the Gecko profile with those calls highlighted: https://perfht.ml/2vGy8WL

Note that they're part of the refresh driver tick, just before each long restyle. (Though the addEmbeddedCSS calls themselves are mostly pretty short -- they just have painful side effects in the form of long restyles.)
addEmbeddedCSS adds a <style> element to the DOM with the given text as its contents:

        function addEmbeddedCSS(cssText, callback) {
          function fireCallbacks() {
            var oldCallbacks = cssCallbacks;
            cssCallbacks = $.Callbacks();
            oldCallbacks.fire().empty();
          }
          if (callback) {
            cssCallbacks.add(callback);
          }
          if (cssText) {
            if (!cssBuffer || cssText.slice(0, '@import'.length) !== '@import') {
              cssBuffer += '\n' + cssText;
              if (!cssBufferTimer) {
                cssBufferTimer = rAF(function () {
                  addEmbeddedCSS();
                });
              }
              return;
            }
          } else {
            cssBufferTimer = null;
            cssText = cssBuffer;
            cssBuffer = '';
          }
          $(newStyleTag(cssText, getMarker()));
          fireCallbacks();
        }
That said, I tried breakpointing in addEmbeddedCSS to see whether I could see what cssText values are being passed in, and I can't get devtools (old debugger) to stop there.  :(

In Chrome I did manage to breakpoint there and there's all sorts of stuff coming through; pretty large stylesheets some of them.  :(
(In reply to Boris Zbarsky [:bz] from comment #5)
> That said, I tried breakpointing in addEmbeddedCSS to see whether I could
> see what cssText values are being passed in, and I can't get devtools (old
> debugger) to stop there.  :(
> 
> In Chrome I did manage to breakpoint there and there's all sorts of stuff
> coming through; pretty large stylesheets some of them.  :(

If you like, you can see the stylesheets in our DevTools inspector (or style editor) -- they're all of the inline <style> elements inside of the <head> element. (Each one of those <style> elements is produced by an addEmbeddedCSS call, modulo addEmbeddedCSS's own coalescing with "cssBuffer".)

I intercepted each call by putting a breakpoint in mozilla::css::Loader::LoadInlineStyle (which is where we parse the [large] text buffer of a just-appended <style> element's contents), and I printed out the string lengths. The three largest stylesheets to go through that path are 47804, 23310, and 15660 characters long, respectively.  So indeed, they're pretty large.

All of these stylesheets are coming after the page has finished loading, though -- the article rendering doesn't visually change very much (if at all) with each of these loads. (Some of them are after the throbber has stopped spinning, too.)
I think the reason the restyles are expensive is that they're triggering nsStyleSet::InvalidateStyleForCSSRuleChanges(), with this backtrace:

#1 in nsStyleSet::InvalidateStyleForCSSRuleChanges() (this=0x7ff722310c50) at layout/style/nsStyleSet.cpp:2427
#2 in mozilla::StyleSetHandle::Ptr::InvalidateStyleForCSSRuleChanges() (this=0x7ff71b3e2018)
       at $obj/dist/include/mozilla/StyleSetHandleInlines.h:267
#3 in nsIPresShell::RestyleForCSSRuleChanges() (this=0x7ff71b3e2000) at layout/base/PresShell.cpp:4584
#4 in mozilla::PresShell::EndUpdate(nsIDocument*, unsigned int) (this=0x7ff71b3e2000, aDocument=0x7ff71ed3b000, aUpdateType=2)
       at layout/base/PresShell.cpp:2542
#5 in nsDocument::EndUpdate(unsigned int) (this=0x7ff71ed3b000, aUpdateType=2) at dom/base/nsDocument.cpp:5107
#6 in nsHTMLDocument::EndUpdate(unsigned int) (this=0x7ff71ed3b000, aUpdateType=2) at dom/html/nsHTMLDocument.cpp:2521


And we take the normal (no-scoped-style) path in InvalidateStyleForCSSRuleChanges(), and hit this code:
>     // If scopeRoots is empty, we know that mStylesHaveChanged was true at
>     // the beginning of this function, and that we need to restyle the whole
>     // document.
>     restyleManager->PostRestyleEvent(root,
>                                      eRestyle_Subtree,
>                                      nsChangeHint(0));
...which makes us restyle the whole document.   And I guess that's particularly painful (i.e. it just takes 75-100ms) simply because it's a large document...? (Or is it due to the nature of the actual new styles?)
Yeah, I can trigger a slow restyle by appending a single bogus new <style> element (with a single bogus rule) to the Obama wikipedia page.

I ran these commands in the Web Console:
  var myStyle = document.createElement("style")
  myStyle.innerText = "foobar { color: purple; }"
  document.head.appendChild(myStyle)
and I profiled the final command, and here's my profile (filtered for DoProcessRestyles): https://perfht.ml/2vYuZkz

There's a 428ms event processing delay, with most of that time spent in DoProcessRestyles, and that's about how long each of the many style flushes are for me (on this particular linux desktop machine) when I profile a normal pageload of this wikipedia page, too.

(The restyle doesn't show a blue bar in this profile for some reason; not sure why, maybe because it came from devtools?)
Perhaps we should suggest to Wikipedia that they batch their <style> element appends together more aggressively?  (i.e. letting more of their addEmbeddedCSS calls coalesce together into a single <style> element, if possible -- or even multiple <style> elements that are appended back-to-back, if they need them to be separated for some reason.)

For what it's worth: I profiled Chrome loading the Obama wikipedia page (using their "Performance" devtools tab), and this is slow there too (not as slow, but still slow enough to miss frame budgets).

I see a total of 300ms spent in "Recalculate Style", split into several slices split out across pageload, with these durations being the restyles that stand out as expensive:
 76.89ms (this one is before addEmbeddedCSS has been called; the rest are after addEmbeddedCSS calls)
 42.43ms
 18.11ms
 25.29ms
 95.57ms

So: Chrome seems to be ~an order of magnitude faster at these restyles, compared to Gecko -- but servo is also about that much faster, based on the "without ABP" measurements in bug 1382319 comment 0.  So Chrome and Firefox-with-stylo seem comparably slow on this pageload I think.

So: is there anything else we can do or should suggest here, beyond perhaps reaching out to Wikipedia about coalescing these updates more aggressively (and beyond shipping stylo so that full-page restyles are faster?)
(In reply to Daniel Holbert [:dholbert] (PTO August 3-7) from comment #9)
> So Chrome and
> Firefox-with-stylo seem comparably slow on this pageload I think.

Calling this qf:p3, given this ^^.  (Hooray for stylo!)
Whiteboard: [qf:p1] → [qf:p3]
Just reprofiled this myself, to get better / more complete numbers (since before, at the end of comment 9, I was comparing numbers from different people & from different bugs).

All of the following measurements are with a fresh browser profile, on Ubuntu Linux (64-bit).  In each case, I captured a performance profile of me going from about:blank to https://en.wikipedia.org/wiki/Barack_Obama

         UA           |  Time with "Restyle" in the stack | Profile URL
-----------------------------------------------------------------------------------------
Nightly without Stylo |  952ms                            |  https://perfht.ml/2vU2eJO
Nightly with Stylo    |  189ms                            |  https://perfht.ml/2wMTCAT
Chrome 60             |  204.8ms                          |  attachment 8896052 [details]

For the chrome profile, I'm getting restyle measurements from their "Call tree" view, which shows a line for "Recalculate Style" with a time measurement of 204.8ms.


SO: this reinforces my conclusion from comment 9 -- Chrome and Firefox-with-Stylo are in the same ballpark for restyling here (with stylo slightly better), and they're both spend about 1/5 as much time as Firefox-with-Gecko.
closed/fixed?
Flags: needinfo?(dholbert)
Priority: -- → P1
(In reply to Daniel Holbert [:dholbert] from comment #9)
> Perhaps we should suggest to Wikipedia that they batch their <style> element
> appends together more aggressively?  (i.e. letting more of their
> addEmbeddedCSS calls coalesce together into a single <style> element, if
> possible -- or even multiple <style> elements that are appended
> back-to-back, if they need them to be separated for some reason.)

Mike, do you know if we know people at Wikipedia for this sort of thing?
Flags: needinfo?(miket)
(In reply to Jet Villegas (:jet) from comment #13)
> closed/fixed?

Sure -- this seems like mostly a non-issue now, per comment 12, so we can call this "fixed-by-stylo" I suppose.

I'll adjust the summary slightly so that this makes sense as a closed bug (since "wikipedia restyles 5-10 times" is still the current state of the world -- it's just not as painful now).
Flags: needinfo?(dholbert)
Flags: needinfo?(cam)
Summary: obama wikipedia page styles things 5-10 times during pageload → obama wikipedia page has slow restyles 5-10 times during pageload
BTW, here's a profile of https://en.wikipedia.org/wiki/Barack_Obama pageload with current Nightly, filtered for "Restyle":
 https://perfht.ml/2f5owBt

207.2ms, still in the same ballpark as we were in on comment 12 (and nearly the same as the Chrome measurement there).
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Depends on: stylo
(In reply to Nathan Froyd [:froydnj] from comment #14)
> (In reply to Daniel Holbert [:dholbert] from comment #9)
> > Perhaps we should suggest to Wikipedia that they batch their <style> element
> > appends together more aggressively?  (i.e. letting more of their
> > addEmbeddedCSS calls coalesce together into a single <style> element, if
> > possible -- or even multiple <style> elements that are appended
> > back-to-back, if they need them to be separated for some reason.)
> 
> Mike, do you know if we know people at Wikipedia for this sort of thing?

We actually have a mailing list set up with the Wikimedia folks. Daniel, are you on that? (I'm happy to send a message to them as well...)
Flags: needinfo?(miket) → needinfo?(dholbert)
I believe I am!  They might just direct us to their bug tracker which is https://phabricator.wikimedia.org/ , though, so I'll start out by filing a bug there and then I'll email the list with a mention of the bug report.
I filed https://phabricator.wikimedia.org/T175866 and emailed the discussion list with the suggestion that they coalesce their style updates if possible.
Flags: needinfo?(dholbert)
Performance Impact: --- → P3
Whiteboard: [qf:p3]
You need to log in before you can comment on or make changes to this bug.