Closed Bug 1451340 Opened 7 years ago Closed 7 years ago

3.25% damp (windows7-32) regression on push e220521c6ff6 (Tue Apr 3 2018)

Categories

(Core :: DOM: Core & HTML, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla61
Tracking Status
firefox-esr52 --- unaffected
firefox59 --- unaffected
firefox60 --- unaffected
firefox61 + fixed

People

(Reporter: igoldan, Assigned: bgrins)

References

Details

(Keywords: perf, regression, talos-regression)

Attachments

(1 file)

Talos has detected a Firefox performance regression from push: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=8f3d33f7c72babbf232f1938e982d4dd5f54f142&tochange=e220521c6ff6ff9a45e19b3917ba95e678fd9932 As author of one of the patches included in that push, we need your help to address this regression. Regressions: 3% damp windows7-32 pgo e10s stylo 70.18 -> 72.47 You can find links to graphs and comparison views for each of the above tests at: https://treeherder.mozilla.org/perf.html#/alerts?id=12476 On the page above you can see an alert for each affected platform as well as a link to a graph showing the history of scores for this test. There is also a link to a treeherder page showing the Talos jobs in a pushlog format. To learn more about the regressing test(s), please see: https://wiki.mozilla.org/Buildbot/Talos/Tests For information on reproducing and debugging the regression, either on try or locally, see: https://wiki.mozilla.org/Buildbot/Talos/Running *** Please let us know your plans within 3 business days, or the offending patch(es) will be backed out! *** Our wiki page outlines the common responses and expectations: https://wiki.mozilla.org/Buildbot/Talos/RegressionBugsHandling
Component: Untriaged → DOM: Core & HTML
Product: Firefox → Core
:bgrins Can you please look over this perf regression?
Flags: needinfo?(bgrinstead)
(In reply to Ionuț Goldan [:igoldan], Performance Sheriffing from comment #1) > :bgrins Can you please look over this perf regression? Sure, I'll see if adding a list of tag names that can't be Custom Elements makes a difference
Assignee: nobody → bgrinstead
Status: NEW → ASSIGNED
Flags: needinfo?(bgrinstead)
(In reply to Ionuț Goldan [:igoldan], Performance Sheriffing from comment #0) > 3% damp windows7-32 pgo e10s stylo 70.18 -> 72.47 > > > You can find links to graphs and comparison views for each of the above > tests at: https://treeherder.mozilla.org/perf.html#/alerts?id=12476 This alert is surprising. A 3% regression is reported, this looks significant. But when you look at subtests: https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=autoland&originalRevision=e220521c6ff6ff9a45e19b3917ba95e678fd9932&newProject=autoland&newRevision=1fb1569b61d292785497c3f662b8a387c638695a&originalSignature=389a5b1ef37772bad22611e4d6237fffea35c9cb&newSignature=389a5b1ef37772bad22611e4d6237fffea35c9cb&showOnlyImportant=1&framework=1 The regression isn't so obvious. We may have regression on: cold.inspector.open by 2.95% inspector.mutations by 5.25% The rest looks like noise and I hope the special average computation talos is using isn't emphasising the noise of complicated.styleeditor.reload.settle and simple.netmonitor.exportHar. Was the alert only on Windows 7? (In reply to Brian Grinstead [:bgrins] from comment #3) > With the blacklist I see -1.40% on win7-32 damp, but it's low confidence: > https://treeherder.mozilla.org/perf.html#/ > compare?originalProject=try&originalRevision=10dfb24dd66e7509c3c4a6bf5186d4e9 > f4f0b8ae&newProject=try&newRevision=ad525e966d2c6a87eaee8e4e2946f772d57d4b18& > framework=1&filter=damp. And in this try run, you do not seem to recover from any regression on these two tests. When looking a the trend for cold.inspector.open, the regression isn't so obvious: https://treeherder.mozilla.org/perf.html#/graphs?series=mozilla-central,1654655,1,1&highlightedRevisions=e220521c6ff6&zoom=1522497031002.7903,1522879360000,727.4390013677546,805.122795501492 While it look more around 770/780 after this patch, it has a lot less noise... The regression may be more visible for inspector.mutations: https://treeherder.mozilla.org/perf.html#/graphs?series=mozilla-central,1654704,1,1&highlightedRevisions=e220521c6ff6&zoom=1522444081940.3022,1522879360000,966.1672756466526,1095.0062269575142 If you have any idea on how to improve DAMP/talos about all that...
(In reply to Alexandre Poirot [:ochameau] from comment #4) > Was the alert only on Windows 7? The regression happens also on Windows 10 and OS X.
OK, when I comment out the early return in IsCustomElementName entirely I see: windows10-64 -2.36% 4.34 (med) windows7-32 -2.66% 3.08 (med) https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=7857baf1fca4be563a2a7716f4a647b91639388f&newProject=try&newRevision=8a7e056c1d155e4219f458e2ddef14b424a80861&framework=1&filter=damp Scanning the subtests, this appears to be due to large high confidence improvements to damp custom.webconsole.close.DAMP custom.webconsole.reload.DAMP. Which is interesting since it's not running in a XUL doc.
(In reply to Brian Grinstead [:bgrins] from comment #6) > Scanning the subtests, this appears to be due to large high confidence > improvements to damp custom.webconsole.close.DAMP > custom.webconsole.reload.DAMP. Which is interesting since it's not running > in a XUL doc. Oh right I missed by how much (+4200%!!) this test increased. I don't have words to say how surprising this is! Here is a profile of DAMP. It may help you as we see very slow function calls related to bindings: https://perfht.ml/2GGsglC nsXBLBinding::UnbindAnonymousContent is taking most of computation time during custom.webconsole.close. Which seems to come from this JS call: https://searchfox.org/mozilla-central/source/devtools/client/webconsole/jsterm.js#1816
Huh, the only XBL anon content I think we'd use in this html doc is for the scrollbar. And I don't know why making it a valid custom element name would change the unbind time, but let me try adding it to the blacklist.
Easy way to reproduce the slow close: ./mach run --setpref devtools.toolbox.selectedTool=webconsole --devtools 'testing/talos/talos/tests/devtools/addon/content/pages/custom/console/index.html?sync=250&stream=250&async=250'
Apparently that DAMP page generates 27036 anon children (xul:scrollbarbutton, xul:slider, and xul:thumb) and 4506 scrollbars (generated by running this in the Browser Toolbox on the previous mach command when targeting webconsole.html): ``` var anonElements = []; var walker = Cc["@mozilla.org/inspector/deep-tree-walker;1"]. createInstance(Ci.inIDeepTreeWalker); walker.showAnonymousContent = true; walker.showSubDocuments = false; walker.showDocumentsAsNodes = false; walker.init(document.documentElement, NodeFilter.SHOW_ELEMENT); while (walker.nextNode()) { var bindingParent = document.getBindingParent(walker.currentNode); if (bindingParent && document.getAnonymousNodes(bindingParent)) { anonElements.push(walker.currentNode); } } anonElements; ```
OK steps to reproduce my testing locally: * Replace `this.hud.outputNode.innerHTML = "";` from Comment 7 with `let n = Date.now(); this.hud.outputNode.innerHTML = ""; console.log("Took " + (Date.now() - n) + "ms to close console");` * ./mach run --setpref devtools.toolbox.selectedTool=webconsole 'testing/talos/talos/tests/devtools/addon/content/pages/custom/console/index.html?sync=250&stream=250&async=250' * Open console and wait for rendering to finish * Close console With no changes I get: console.log: "Took 17965ms to close console" If I return false on `scrollbar`, `scrollbarbutton`, `slider`, `thumb` I get: "Took 364ms to close console"
Looks like the reason we have so many scrollbars in the console is that we have `.tree { overflow: auto; }` and that gets used for every logged object that can be expanded.
Comment on attachment 8965419 [details] Bug 1451340 - Don't attempt to RegisterUnresolvedElement for native anonymous content; https://reviewboard.mozilla.org/r/234172/#review239804
Attachment #8965419 - Flags: review?(bugs) → review+
Pushed by bgrinstead@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/4a148fbce5fc Don't attempt to RegisterUnresolvedElement for native anonymous content;r=smaug
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
== Change summary for alert #12549 (as of Fri, 06 Apr 2018 02:16:59 GMT) == Improvements: 5% damp linux64 opt e10s stylo 64.23 -> 60.84 5% damp windows10-64 opt e10s stylo75.48 -> 71.95 3% damp windows7-32 opt e10s stylo 83.25 -> 80.36 3% damp windows10-64 pgo e10s stylo69.94 -> 67.77 For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=12549
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: