Last Comment Bug 801977 - "Reddit Enhancement Suite" causes slow comment page loads
: "Reddit Enhancement Suite" causes slow comment page loads
Status: NEW
:
Product: Tech Evangelism
Classification: Other
Component: Add-ons (show other bugs)
: unspecified
: x86 Mac OS X
: -- normal (vote)
: ---
Assigned To: Nobody; OK to take it and work on it
:
:
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-10-15 18:56 PDT by Benoit Girard (:BenWa)
Modified: 2014-10-24 15:56 PDT (History)
4 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---


Attachments

Description Benoit Girard (:BenWa) 2012-10-15 18:56:29 PDT
Add-on link: https://addons.mozilla.org/en-US/firefox/addon/reddit-enhancement-suite/?src=api

STR:
1) Load a reddit.com comment page
2) Notice slow loading (spinner animation skips), blocks event for ~ 2 seconds.
 
http://people.mozilla.com/~bgirard/cleopatra/?report=4c5e83f5663937ac2c81b124427e209e236658c7

Here's a very rough breakdown of time directly triggered from RES:
1) RESInit() 0.7 seconds
* 42ms - modules.uppersAndDowners.go() @ reddit_enhancement_suite.user.js:3339
RESInit() @ reddit_enhancement_suite.user.js:16345
* 139ms - modules.keyboardNav.go() @ reddit_enhancement_suite.user.js:3888
* 262ms - modules.userTagger.go() @ reddit_enhancement_suite.user.js:5272
* Various other modules
2) JQuery calls GetOffsetHeight causing a 200ms reflow

And various other steps taking 50-100ms
Comment 1 Jorge Villalobos [:jorgev] 2012-10-16 09:56:35 PDT
Adding RES developer.
Comment 2 Steve Sobel 2014-10-24 08:37:35 PDT
what version of RES are you running? Have you pulled the latest (not yet approved) from AMO, or are you running 4.5.0.2?

RES does just have a boatload of things going that you can turn on/off to help performance if you're not using them, but certainly we want to do what we can to make it as efficient as possible.
Comment 3 Benoit Girard (:BenWa) 2014-10-24 08:58:33 PDT
Is the new version 4.5.2[1]? I can get fresh profile and look for any obvious performance pitfall (like #2 above) if you have time to take a look.

[1] https://addons.mozilla.org/en-US/firefox/addon/reddit-enhancement-suite/versions/?page=1#version-4.5.2
Comment 4 Steve Sobel 2014-10-24 09:00:17 PDT
yeah, 4.5.2 is the newest.

I would be happy to look in to any specific performance issues you identify.  RES does a ton of DOM manipulation, so it's somewhat CPU heavy especially on large comments pages, so there's certainly a ceiling as far as just how fast we can make it - but if we're doing something inefficiently that has more efficient alternatives, I definitely want to get to the bottom of that!
Comment 5 Benoit Girard (:BenWa) 2014-10-24 09:12:49 PDT
Here's a fresh profile. Page load here is 3 second long and it looks like the style cost are out of control.

http://people.mozilla.org/~bgirard/cleopatra/#report=ce066131b05a8d113e50f01b558c1c566b4867e0

STR:
1) Install https://addons.mozilla.org/en-US/firefox/addon/reddit-enhancement-suite/versions/?page=1#version-4.5.2
2) Visit http://www.reddit.com/r/worldnews/comments/1fwhkx/what_we_have_is_concrete_proof_of_usbased/

dholbert can you point out anything obvious why restyle would be so costly here:
mozilla::ElementRestyler::RestyleContentChildren(nsIFrame*, nsRestyleHint)
mozilla::ElementRestyler::RestyleChildren(nsRestyleHint)
mozilla::ElementRestyler::Restyle(nsRestyleHint)
mozilla::ElementRestyler::RestyleContentChildren(nsIFrame*, nsRestyleHint)

I'm seeing this nested about 30-40 frames deep in the profile. Each restyle flush takes 200ms and we have several.

Steve, modules.commentPreview.addBigEditor() @ commentPreview.js:285 is calling something in jquery which forces a synchronous style flush. If this is avoidable then that's probably an easy 200ms win.
Comment 6 Daniel Holbert [:dholbert] 2014-10-24 11:46:50 PDT
It looks like in at least one case, there's a pending restyle for the <body> element, which gets flushed because some JQuery JS requests the computed value of "display" for some element.

In another case, there's a pending restyle for the <html> element, which gets flushed because one of the addon's scripts asks for computed style data, to get computed "color" property. (at userHighlight.js:191)

(In both cases, we have hint eRestyle_Subtree, which I think means we restyle the whole document.)

Not sure what's posting these pending restyles yet.
Comment 7 Daniel Holbert [:dholbert] 2014-10-24 13:03:32 PDT
I think the pending restyles come from...
  (1) stylesheets & <style> elements finishing being parsed, and 
  (2) setting "class" attributes on the <html> & <body> elements

On the <body> element, we get a call to set class="single-page comments-page res res-v430 res-navTop".

On the <html> element, we get calls to set class="res-commentBoxes" and then "res-commentBoxes res-commentBoxes-rounded".

Each of these changes make us call AddPendingRestyle eRestyle_Subtree on the element in question (the <body> or <html> element), so they put us in a position where a style flush will be expensive. I'm not sure whether these are the styles changes that get flushed by the script's getComputedStyle() queries, but it seems likely.

If possible, the addon should tweak the "class" attr on <html> & <body> as early as possible (so that restyling is cheap), and in as localized a spot as possible (without style flushes between the attribute tweaks, so that we don't have to recompute style based on intermediate "class" values).
Comment 8 Steve Sobel 2014-10-24 13:12:45 PDT
thank you Daniel, that is helpful information.

RES does have some code that tries to run early on in the process and might be able to style those elements earlier. I will need to have a look at just how early we can reliably do it. There's a lot going on with async preference grabbing first (which determines whether or not to add a class like commentBoxes, for example), but I believe we can still get there early enough. I will have a look!
Comment 9 Daniel Holbert [:dholbert] 2014-10-24 13:40:46 PDT
Thanks!

Also -- the batching is *at least* as important as the doing-it-early (probably more important).  My #1 suggestion would be to make all the <html>/<body> class-tweaks at the same time -- e.g.

  var extraHTMLClasses = [];
  var extraBodyClasses = [];
  [...]
  if (whatever) {
    extraHTMLClasses.push("res-commentBoxes");
  }
  [... more stuff like that ...]

And then in some piece of code where you *know* you're done doing your pref-reads & building up your class lists, throw all of those classes into the html / body classLists.  (the earlier the better, of course)
Comment 10 Steve Sobel 2014-10-24 13:56:04 PDT
I've already got something nearly exactly like this, I'm about to submit a commit and link you to it on github! :-)
Comment 11 Steve Sobel 2014-10-24 14:00:10 PDT
Please take a peek and let me know what you think! I'd be happy to send you an XPI to test out if you're willing!

https://github.com/honestbleeps/Reddit-Enhancement-Suite/commit/2f8c80b4c34592b54f78dba488ae8eac4d73e5d1
Comment 12 Daniel Holbert [:dholbert] 2014-10-24 14:12:52 PDT
Seems reasonable to me! I'm open to testing an XPI, too -- maybe send it to BenWa as well, since we're working off of his profile (from comment 5).
Comment 13 Benoit Girard (:BenWa) 2014-10-24 14:34:21 PDT
New profile:
http://people.mozilla.org/~bgirard/cleopatra/#report=d528afa086658177d23899af6bd0e5f7d78c5853&search=flush_style

This looks much better! The first restyle is shorter by 100ms, the addBigEditor flush is still there, two style flushes are gone from modules.styleTweaks.go() @ styleTweaks.js:213 and RESUtils.getComputedStyle() @ utils.js:1745.

Keep in mind my setup isn't scientific so if things are non deterministic then that could skew the results. We're spending about 50% in style flushes if this wasn't a fluke.
Comment 14 Steve Sobel 2014-10-24 14:43:07 PDT
hrm I'm not understanding why there's a flush from addBigEditor unless it's this, which is a bit silly, I'll just add style="display: none;"... but still:

var editor = $('<div id="BigEditor">').hide();

beyond that, the only code that adds a class to the body or anything happens on button click. can you give any more detail on what you're seeing in that flush?

thanks again, really appreciate all your help
Comment 15 Benoit Girard (:BenWa) 2014-10-24 15:06:38 PDT
Yes, it's coming from the hide(). It's hard to tell since JQuery is minified. This calls (bottom up):
nsComputedDOMStyle::UpdateCurrentStyleSources(bool)
nsComputedDOMStyle::GetPropertyCSSValue(nsAString_internal const&, mozilla::ErrorResult&)
nsComputedDOMStyle::GetPropertyValue(nsAString_internal const&, nsAString_internal&)
mozilla::dom::CSSStyleDeclarationBinding::getPropertyValue(JSContext*, JS::Handle<JSObject*>, nsICSSDeclaration*, JSJitMethodCallArgs const&)
mozilla::dom::GenericBindingMethod(JSContext*, unsigned int, JS::Value*)
Comment 16 Daniel Holbert [:dholbert] 2014-10-24 15:20:42 PDT
Here's the unminified jquery 1.11.1 source:
 http://code.jquery.com/jquery-1.11.1.js

That shows that hide() is a wrapper for showHide(), which contains this line:
>  jQuery._data( elem, "olddisplay", hidden ? display : jQuery.css( elem, "display" ) );

And the jQuery.css(elem, "display") invocation there is looking up computed-style data, as documented here:  http://api.jquery.com/css/  And computed-style lookups do indeed need to flush styles.

SO: if you can just directly set style.display = "none" yourself (as you suggested in comment 14), it seems like you should do that, to avoid this flush.
Comment 17 Steve Sobel 2014-10-24 15:23:26 PDT
yep, thanks, I already sent you a new xpi that does not only that, but also just doesn't even run that entire function until it's user-invoked. It shouldn't have been appending to the DOM unless necessary anyhow!
Comment 18 Benoit Girard (:BenWa) 2014-10-24 15:35:17 PDT
Yes it's gone :D. But I say the flush from RESUtils.getComputedStyle() this time:

PresShell::Flush (Flush_Style)
PresShell::FlushPendingNotifications(mozilla::ChangesToFlush)
nsDocument::FlushPendingNotifications(mozFlushType)
nsComputedDOMStyle::UpdateCurrentStyleSources(bool)
nsComputedDOMStyle::GetPropertyCSSValue(nsAString_internal const&, mozilla::ErrorResult&)
nsComputedDOMStyle::GetPropertyValue(nsAString_internal const&, nsAString_internal&)
mozilla::dom::CSSStyleDeclarationBinding::getPropertyValue(JSContext*, JS::Handle<JSObject*>, nsICSSDeclaration*, JSJitMethodCallArgs const&)
mozilla::dom::GenericBindingMethod(JSContext*, unsigned int, JS::Value*)
js::Invoke(JSContext*, JS::CallArgs, js::MaybeConstruct)
Interpret(JSContext*, js::RunState&)
RESUtils.getComputedStyle() @ utils.js:1750
modules.userHighlight.findDefaults() @ userHighlight.js:181
modules.userHighlight.go() @ userHighlight.js:160
Comment 19 Steve Sobel 2014-10-24 15:52:43 PDT
got it... I didn't write that bit and I think it is maybe no longer really needed, we're going to look at stripping that out altogether! thanks
Comment 20 Benoit Girard (:BenWa) 2014-10-24 15:56:26 PDT
Sweet, thanks for the quick responses. FWIW I imagine this will also translate into performance wins on chrome since these are fundamental fitfalls with the web platform (but the magnitude will differ).

Note You need to log in before you can comment on or make changes to this bug.