Add a simple tool to display reflows

VERIFIED FIXED in Firefox 27

Status

()

Firefox
Developer Tools
VERIFIED FIXED
4 years ago
3 years ago

People

(Reporter: vingtetun, Assigned: paul)

Tracking

({feature})

Trunk
Firefox 27
feature
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 14 obsolete attachments)

31.22 KB, patch
paul
: review+
Details | Diff | Splinter Review
Created attachment 816516 [details] [diff] [review]
Show reflows for b2g app WIP

It would be useful for developers to have a way to display the reflows happening on a page. For Gaia it would be useful to save some load time and to fix some responsiveness issues.

I made a small hack on top of a platform feature (bug 453650) that display the reflows (with a stack if they comes from JS) and the time spent on them. It already shows me that the LazyLoad of some of our CSS files is extremelly expensive and hurt the page responsiveness after a page load.

It also shows some weird things in the sms app.

So it would be very helpful to have that as a tool instead as a hack for app developers.
Keywords: perf
(Assignee)

Comment 1

4 years ago
Working on that…
Assignee: nobody → paul
(Assignee)

Comment 2

4 years ago
Created attachment 816600 [details] [diff] [review]
Patch v0.1 - WIP

The plan is to create a "LOG" section in the WebConsole, that is off by default, which will show the reflow events.
Attachment #816516 - Attachment is obsolete: true
I wonder if we could use that new section to add other interesting events, like GC events for example. Although Log sounds too similar to the existing Logging category to be honest.
(Assignee)

Comment 4

4 years ago
Created attachment 816616 [details] [diff] [review]
Patch v0.2 - WIP

Mihai, can you look at this patch? I know it's ugly, but before going further, I'll like to get your feedback.

I show the reflow in "Log" section in the CSS tab. It's disabled by default. These events are batched, so we don't get flooded with logs.

Also, how can we start recording reflow events only when the log section is activated?
Attachment #816600 - Attachment is obsolete: true
Attachment #816616 - Flags: feedback?(mihai.sucan)
(Assignee)

Comment 5

4 years ago
Created attachment 816623 [details] [diff] [review]
Patch v0.3

+ function name.
(Assignee)

Comment 6

4 years ago
Created attachment 816624 [details]
screenshot: reflow in the homescreen app
(Assignee)

Comment 7

4 years ago
Comment on attachment 816623 [details] [diff] [review]
Patch v0.3

Vivien, does that address your needs? I don't show the full stack, but it opens the debugger. From here, you can add a breakpoint and start debugging. I don't show if the reflow is interruptible or not.
Attachment #816623 - Flags: feedback?(21)
(In reply to Paul Rouget [:paul] from comment #7)
> Comment on attachment 816623 [details] [diff] [review]
> Patch v0.3
> 
> Vivien, does that address your needs? I don't show the full stack, but it
> opens the debugger. From here, you can add a breakpoint and start debugging.
> I don't show if the reflow is interruptible or not.

I think that's good enough as a start yes. Then we can iterate from that.
Comment on attachment 816623 [details] [diff] [review]
Patch v0.3

Review of attachment 816623 [details] [diff] [review]:
-----------------------------------------------------------------

Patch looks good. See comments below for improvements.

::: browser/devtools/webconsole/webconsole.js
@@ +1541,5 @@
> +    let span = this.document.createElementNS(XHTML_NS, "span");
> +    if (functionName) {
> +      span.textContent = "reflow (" + functionName + "): " + duration + "ms";
> +    } else {
> +      span.textContent = "reflow: " + duration + "ms";

span.textContent needs to be a localizable string.

@@ +1543,5 @@
> +      span.textContent = "reflow (" + functionName + "): " + duration + "ms";
> +    } else {
> +      span.textContent = "reflow: " + duration + "ms";
> +    }
> +    span.draggable = false;

draggable=false is needed only for anchors.

@@ +2313,5 @@
>     *         output node.
>     */
>    createMessageNode:
>    function WCF_createMessageNode(aCategory, aSeverity, aBody, aSourceURL,
> +                                 aSourceLine, aClipboardText, aLevel, aTimeStamp, aTarget)

Please do not add another argument to createMessageNode(). We will remove this function as soon as possible.

However, I like the idea of a target argument for createLocationNode(), so keep that.

@@ +2372,5 @@
>  
>      // Add the message repeats node only when needed.
>      let repeatNode = null;
>      if (aCategory != CATEGORY_INPUT && aCategory != CATEGORY_OUTPUT &&
> +        aCategory != CATEGORY_NETWORK && aCategory != CATEGORY_CSS) {

This is going to break css message repeats detection. Please make sure repeatNode is not added only for reflow-related messages.

@@ +2394,5 @@
>      // Create the source location (e.g. www.example.com:6) that sits on the
>      // right side of the message, if applicable.
>      let locationNode;
>      if (aSourceURL && IGNORED_SOURCE_URLS.indexOf(aSourceURL) == -1) {
> +      locationNode = this.createLocationNode(aSourceURL, aSourceLine, aTarget);

This looks good but I think you can determine |aTarget| here based on message category, instead of adding the |aTarget| argument to the createMessageNode() function.

@@ +4836,5 @@
>     */
>    _attachConsole: function WCCP__attachConsole()
>    {
>      let listeners = ["PageError", "ConsoleAPI", "NetworkActivity",
> +                     "FileActivity", "ReflowActivity"];

Please start the ReflowActivity listener only when the csslog filter pref is enabled, and stop it when it's disabled.

https://developer.mozilla.org/en-US/docs/Tools/Web_Console/remoting#startListeners%28listeners.2C_onResponse%29
Attachment #816623 - Flags: feedback+

Updated

4 years ago
Attachment #816616 - Flags: feedback?(mihai.sucan) → feedback+
Comment on attachment 816623 [details] [diff] [review]
Patch v0.3

Review of attachment 816623 [details] [diff] [review]:
-----------------------------------------------------------------

Sounds a good start.
Attachment #816623 - Flags: feedback?(21) → feedback+
Tim,
the reflow observer from bug 453650 is awesome and extremely helpful. Do you know if there is a way to provide more informations for all those reflows that does not have a stack, like the one that comes from CSS from example?

This will help a lot when debugging reflows issues on FirefoxOS and likely for the rest of the world as well.
Flags: needinfo?(ttaubert)
(Assignee)

Comment 12

4 years ago
(In reply to Vivien Nicolas (:vingtetun) (:21) from comment #11)
> Tim,
> the reflow observer from bug 453650 is awesome and extremely helpful. Do you
> know if there is a way to provide more informations for all those reflows
> that does not have a stack, like the one that comes from CSS from example?
> 
> This will help a lot when debugging reflows issues on FirefoxOS and likely
> for the rest of the world as well.

What kind of info do you want exactly? Let's imagine the reflow is triggered by a user action:

div {
  margin:  0px;
}
div:hover {
  margin: 10px;
}

What kind of log do you see here?
(In reply to Paul Rouget [:paul] from comment #12)
> (In reply to Vivien Nicolas (:vingtetun) (:21) from comment #11)
> > Tim,
> > the reflow observer from bug 453650 is awesome and extremely helpful. Do you
> > know if there is a way to provide more informations for all those reflows
> > that does not have a stack, like the one that comes from CSS from example?
> > 
> > This will help a lot when debugging reflows issues on FirefoxOS and likely
> > for the rest of the world as well.
> 
> What kind of info do you want exactly? Let's imagine the reflow is triggered
> by a user action:
> 
> div {
>   margin:  0px;
> }
> div:hover {
>   margin: 10px;
> }
> 
> What kind of log do you see here?

Knowing that it comes from div:hover would be priceless. I can imagine that if reflows are batched, the first of the series that has triggered the reflows would be nice.
Tracking synchronous reflows and trying to avoid them is one thing. Something else we should look into is some way of knowing why certain frames have been invalidated. That could be a :hover, some JS code changing CSS classes, etc.

Maybe we could include some devtool that would highlight elements that have been invalidated (a little like paint flashing) and would provide a list of events including why the element was invalidated?
Flags: needinfo?(ttaubert)
(Assignee)

Comment 15

4 years ago
Created attachment 817859 [details] [diff] [review]
Actors code - V1
Attachment #816616 - Attachment is obsolete: true
Attachment #816623 - Attachment is obsolete: true
Attachment #817859 - Flags: review?(mihai.sucan)
(Assignee)

Comment 16

4 years ago
Created attachment 817860 [details] [diff] [review]
Frontend code - V1
Attachment #817860 - Flags: review?(mihai.sucan)
(Assignee)

Comment 17

4 years ago
Created attachment 817861 [details] [diff] [review]
Test - V1
Attachment #817861 - Flags: review?(mihai.sucan)
Comment on attachment 817859 [details] [diff] [review]
Actors code - V1

Review of attachment 817859 [details] [diff] [review]:
-----------------------------------------------------------------

Patch looks good. r+

::: toolkit/devtools/client/dbg-client.jsm
@@ +185,5 @@
>  const UnsolicitedNotifications = {
>    "consoleAPICall": "consoleAPICall",
>    "eventNotification": "eventNotification",
>    "fileActivity": "fileActivity",
> +  "reflowActivity": "reflowActivity",

nit: this is supposed to be an alphabetic list.

::: toolkit/devtools/webconsole/utils.js
@@ +2590,5 @@
>  };
>  
> +
> +/**
> + * A ReflowObserver that listens for reflow events from the page.

nit: please mention this is an nsIReflowObserver implementation.

@@ +2602,5 @@
> + */
> +
> +function ConsoleReflowListener(aWindow, aListener)
> +{
> +  this.docshell = aWindow.QueryInterface(Ci.nsIInterfaceRequestor).getInterface(Ci.nsIWebNavigation).QueryInterface(Ci.nsIDocShell);

nit: please wrap at 80 chars.

@@ +2614,5 @@
> +  QueryInterface: XPCOMUtils.generateQI([Ci.nsIReflowObserver, Ci.nsISupportsWeakReference]),
> +  docshell: null,
> +  listener: null,
> +
> +  sendReflow: function(start, end, interruptible) {

nit: for consistency with the rest of the file please use named functions, arguments with the "a" prefix, jsdoc comments, and new line before curly bracket.
Attachment #817859 - Flags: review?(mihai.sucan) → review+
Comment on attachment 817860 [details] [diff] [review]
Frontend code - V1

Review of attachment 817860 [details] [diff] [review]:
-----------------------------------------------------------------

Patch looks good. r+ with the comments below addressed.

::: browser/devtools/webconsole/webconsole.js
@@ +575,5 @@
>    /**
> +   * Attach / detach reflow listeners depending on the checked status
> +   * of the `CSS > Log` menuitem.
> +   */
> +  updateReflowActivityListener: function WCCP__updateReflowActivityListener() {

Please mark this method as private.

s/WCCP/WCF/

nit: new line before curly brace, for consistency.

@@ +761,5 @@
>          target.setAttribute("checked", state);
>  
>          let prefKey = target.getAttribute("prefKey");
>          this.setFilterState(prefKey, state);
> +        this.updateReflowActivityListener();

Maybe call updateReflowActivityListener() in setFilterState()?

@@ +1550,5 @@
>    {
>      this.outputMessage(CATEGORY_NETWORK, this.logFileActivity, [aFileURI]);
>    },
>  
> +  logReflowActivity: function WCF_logReflowActivity(aMessage)

Please add jsdoc comments to the new functions.

@@ +1555,5 @@
> +  {
> +    let {start, end, sourceURL, sourceLine} = aMessage;
> +    let duration = Math.round((end - start) * 100) / 100;
> +    let node = this.document.createElementNS(XHTML_NS, "span");
> +    if (sourceURL) {

How can I trigger a reflow with a link?

::: browser/locales/en-US/chrome/browser/devtools/webconsole.properties
@@ +88,5 @@
>  # using their type (from the constructor function) in this descriptive string.
>  # Parameters: %S is the object type.
>  gcliterm.instanceLabel=Instance of %S
>  
> +reflow.messageWithLink=reflow: %Sms\u0020

Maybe add a localization note for these new strings explaining when they show up.
Attachment #817860 - Flags: review?(mihai.sucan) → review+
Comment on attachment 817861 [details] [diff] [review]
Test - V1

Review of attachment 817861 [details] [diff] [review]:
-----------------------------------------------------------------

This is looking good. r+

Can you please also add a webconsole test in browser/ ? Thank you!

::: toolkit/devtools/webconsole/test/test_reflow.html
@@ +1,5 @@
> +<!DOCTYPE HTML>
> +<html lang="en">
> +<head>
> +  <meta charset="utf8">
> +  <title>Test for the Console API</title>

Please update the title to reflect the test's purpose.

@@ +34,5 @@
> +  client = aState.dbgClient;
> +
> +  onReflowActivity = onReflowActivity.bind(null, aState);
> +  client.addListener("reflowActivity", onReflowActivity);
> +  iter = generateReflow();

Is generateReflow() a function yields?
Attachment #817861 - Flags: review?(mihai.sucan) → review+
> @@ +34,5 @@
> > +  client = aState.dbgClient;
> > +
> > +  onReflowActivity = onReflowActivity.bind(null, aState);
> > +  client.addListener("reflowActivity", onReflowActivity);
> > +  iter = generateReflow();
> 
> Is generateReflow() a function yields?

Is generateReflow() a function that yields?
Can we open a followup to have a stack when some JS code is triggering reflows by toggling a CSS class?
(Assignee)

Comment 23

4 years ago
Created attachment 818952 [details] [diff] [review]
addendum

Mihai, I'll address all your comments in a combined patch. The 2 big changes are this addendum and the browser/webconsole test.
(Assignee)

Comment 24

4 years ago
And there's a type in the comment in the addendum. I'll fix that.
(Assignee)

Comment 25

4 years ago
Created attachment 818956 [details] [diff] [review]
All-in-one

Addressed all the comments. Added the addendum with type fixed, and added a webconsole browser test.
(Assignee)

Comment 26

4 years ago
https://tbpl.mozilla.org/?tree=Try&rev=6b917d35c4fe
(Assignee)

Comment 27

4 years ago
Orange. I might need to force the reflow…
(Assignee)

Comment 28

4 years ago
Created attachment 819011 [details] [diff] [review]
addendum 2

When testing this, we need to know when the page is actually listening to reflows. So once the observer is added, the actor send a {message:"listen-on"} packet.
(Assignee)

Comment 29

4 years ago
Created attachment 819014 [details] [diff] [review]
All-in-one v2 (with new packets)

https://tbpl.mozilla.org/?tree=Try&rev=1bc4a19ae775
Attachment #818956 - Attachment is obsolete: true
Comment on attachment 819011 [details] [diff] [review]
addendum 2

I'm not sure this approach is the best approach. You should not need packet changes, or anything like 'listen-on'.

You have WCF__updateReflowActivityListener() which calls start/stopListener(), and you have the option to add a callback, the server already notifies the client when the reflow listener is started, with a response packet. You only need to add a second argument to startListener() in the aforementioned private method. You can do this.emit("listeners-started", responsePacket.startedListeners). From the test you can then do hud.ui.once("listeners-started", ...).

I believe it's all doable in the client, in a nicer way. Thank you!
(Assignee)

Comment 31

4 years ago
Addressed Mihai's comment: https://tbpl.mozilla.org/?tree=Try&rev=42fe5a91d975
(Assignee)

Comment 32

4 years ago
Created attachment 819033 [details] [diff] [review]
All-in-one v3 (using listeners instead of new packet)

Mihai, if this turns green, maybe you want to r+ this patch again.
Attachment #816624 - Attachment is obsolete: true
Attachment #817859 - Attachment is obsolete: true
Attachment #817860 - Attachment is obsolete: true
Attachment #817861 - Attachment is obsolete: true
Attachment #818952 - Attachment is obsolete: true
Attachment #819011 - Attachment is obsolete: true
Attachment #819014 - Attachment is obsolete: true
Comment on attachment 819033 [details] [diff] [review]
All-in-one v3 (using listeners instead of new packet)

Review of attachment 819033 [details] [diff] [review]:
-----------------------------------------------------------------

Patch looks good. Thanks for the update!

There's a typo in the patch commit message: s/r=mscucan/r=msucan/ please :)
Attachment #819033 - Flags: review+
(Assignee)

Comment 34

4 years ago
Created attachment 819039 [details] [diff] [review]
patch with correct commit message
Attachment #819033 - Attachment is obsolete: true
Attachment #819039 - Flags: review+
(Assignee)

Comment 35

4 years ago
https://tbpl.mozilla.org/?tree=Try&rev=77ea3208346a
(Assignee)

Comment 36

4 years ago
Filed bug 929469: Show why layout has been invalidated.
(Assignee)

Comment 37

4 years ago
Still orange. Damnit.
(Assignee)

Comment 38

4 years ago
Created attachment 820374 [details] [diff] [review]
final patch

This should do it.

https://tbpl.mozilla.org/?tree=Try&rev=1ef3ecc337b4
Attachment #819039 - Attachment is obsolete: true
Attachment #820374 - Flags: review+
(Assignee)

Updated

4 years ago
Keywords: perf → checkin-needed
https://hg.mozilla.org/integration/fx-team/rev/18684ec60867
Keywords: checkin-needed
Whiteboard: [fixed-in-fx-team]
(Assignee)

Updated

4 years ago
Keywords: feature
https://hg.mozilla.org/mozilla-central/rev/18684ec60867
Status: NEW → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Whiteboard: [fixed-in-fx-team]
Target Milestone: --- → Firefox 27
QA Contact: petruta.rasa
Feature signed-off on Firefox 27.0a2 (20131128004001), tested on the next OSs: Windows 7 64bit, Windows 8 32bit, Ubuntu 13.04 32bit, Mac OSX 10.8.5, Firefox OS 1.3.0.0-prerelease (on an unagi device).
Status: RESOLVED → VERIFIED
Blocks: 960933
This is showing up in profiles, see CRL_reflowInterruptible() @ utils.js:
http://people.mozilla.org/~bgirard/cleopatra/#report=c39094f56267ab0999b67915ba91205152211875

I don't have any devtools/app manager or anything of that sort attached.

Can we not have this run when we don't have anything listening?
Flags: needinfo?(paul)
(Assignee)

Comment 43

3 years ago
(In reply to Benoit Girard (:BenWa) from comment #42)
> This is showing up in profiles, see CRL_reflowInterruptible() @ utils.js:
> http://people.mozilla.org/~bgirard/cleopatra/
> #report=c39094f56267ab0999b67915ba91205152211875
> 
> I don't have any devtools/app manager or anything of that sort attached.
> 
> Can we not have this run when we don't have anything listening?

I'm not sure how to read your graph, but are you saying that we still listen to reflows when the devtools are not running?
Flags: needinfo?(paul)
(In reply to Paul Rouget [:paul] (slow to respond. Ping me on IRC) from comment #43)
> I'm not sure how to read your graph, but are you saying that we still listen
> to reflows when the devtools are not running?

Yes, we're paying the performance cost. I noticed that now enabling the FPS counter incorrectly requires turning on the developer HUD from the Developer tab so that may be why we're seeing this show up.
(Assignee)

Comment 45

3 years ago
Jan, can you look at this? I think you fixed this recently.
Flags: needinfo?(janx)
Yes, I explained that particular regression to Benoit in bug 987951 comment 15, and fixed it in bug 989272 by allowing control over the FPS and TTL monitors independently from the Developer HUD (the fix landed in Gaia about 30h ago).
Flags: needinfo?(janx)
Sounds good to me

Updated

3 years ago
See Also: → bug 926922
You need to log in before you can comment on or make changes to this bug.