Open Bug 1356863 Opened 7 years ago Updated 2 years ago

Several uninterruptable reflows caused by toggling devtool theme

Categories

(DevTools :: General, defect, P4)

Product:
DevTools
Component:
General
Type:
defect

Tracking

(Performance Impact:none)

Project Flags:
Performance Impact none

People

(Reporter: rjward0, Unassigned)

References

Details

(Keywords: perf, Whiteboard: [ohnoreflow][fxperf:p5]) 

1.2ms uninterruptible reflow at waitForSyncCallback@resource://services-common/async.js:98:7

Here's the stack:

waitForSyncCallback@resource://services-common/async.js:98:7
makeSpinningCallback/callback.wait@resource://services-common/async.js:168:27
_handlerListener@resource://services-sync/addonsreconciler.js:633:9
onEnabled@resource://services-sync/addonsreconciler.js:645:5
callAddonListeners@resource://gre/modules/AddonManager.jsm:1693:11
callAddonListeners@resource://gre/modules/AddonManager.jsm:3160:5
addonChanged@resource://gre/modules/LightweightThemeManager.jsm:419:9
callProvider@resource://gre/modules/AddonManager.jsm:268:12
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:1741:7
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:3141:5
_setCurrentTheme@resource://gre/modules/LightweightThemeManager.jsm:707:3
set currentTheme@resource://gre/modules/LightweightThemeManager.jsm:157:12
updateDevtoolsThemeAttribute@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:164:46
observe@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:184:13
SetPref@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:37:14
createThemeOption/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:283:9
EventListener.handleEvent*createThemeOption@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:282:7
setupThemeList@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:298:28
OptionsPanel.prototype.open<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:92:5
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:311:39
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
_handleResultValue@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:387:7
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:319:13
TaskImpl@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:273:3
asyncFunction@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:247:14
onLoad@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox.js:1476:19





1.2ms uninterruptible reflow at _onLazyResize@resource:///modules/CustomizableUI.jsm:4248:1


_onLazyResize@resource:///modules/CustomizableUI.jsm:4248:1
asyncFunction@resource://gre/modules/Task.jsm:241:18
Task_spawn@resource://gre/modules/Task.jsm:166:12
_timerCallback/<@resource://gre/modules/DeferredTask.jsm:277:13
TaskImpl_run@resource://gre/modules/Task.jsm:319:42
TaskImpl@resource://gre/modules/Task.jsm:277:3
asyncFunction@resource://gre/modules/Task.jsm:252:14
Task_spawn@resource://gre/modules/Task.jsm:166:12
_timerCallback@resource://gre/modules/DeferredTask.jsm:275:29
waitForSyncCallback@resource://services-common/async.js:98:7
makeSpinningCallback/callback.wait@resource://services-common/async.js:168:27
_handlerListener@resource://services-sync/addonsreconciler.js:633:9
onEnabled@resource://services-sync/addonsreconciler.js:645:5
callAddonListeners@resource://gre/modules/AddonManager.jsm:1693:11
callAddonListeners@resource://gre/modules/AddonManager.jsm:3160:5
addonChanged@resource://gre/modules/LightweightThemeManager.jsm:419:9
callProvider@resource://gre/modules/AddonManager.jsm:268:12
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:1741:7
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:3141:5
_setCurrentTheme@resource://gre/modules/LightweightThemeManager.jsm:707:3
set currentTheme@resource://gre/modules/LightweightThemeManager.jsm:157:12
updateDevtoolsThemeAttribute@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:164:46
observe@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:184:13
SetPref@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:37:14
createThemeOption/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:283:9
waitForSyncCallback@resource://services-common/async.js:98:7
Res__request@resource://services-sync/resource.js:386:14
Res_get@resource://services-sync/resource.js:415:12
_fetchServerConfiguration@resource://services-sync/service.js:848:24
_remoteSetup@resource://services-sync/service.js:873:10
sync@resource://services-sync/stages/enginesync.js:132:15
onNotify@resource://services-sync/service.js:1073:7
WrappedNotify@resource://services-sync/util.js:163:21
WrappedLock@resource://services-sync/util.js:119:16
_lockedSync@resource://services-sync/service.js:1063:12
sync/<@resource://services-sync/service.js:1055:7
WrappedCatch@resource://services-sync/util.js:94:16
sync@resource://services-sync/service.js:1044:5
waitForSyncCallback@resource://services-common/async.js:98:7
makeSpinningCallback/callback.wait@resource://services-common/async.js:168:27
_handlerListener@resource://services-sync/addonsreconciler.js:633:9
onEnabled@resource://services-sync/addonsreconciler.js:645:5
callAddonListeners@resource://gre/modules/AddonManager.jsm:1693:11
callAddonListeners@resource://gre/modules/AddonManager.jsm:3160:5
addonChanged@resource://gre/modules/LightweightThemeManager.jsm:419:9
callProvider@resource://gre/modules/AddonManager.jsm:268:12
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:1741:7
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:3141:5
_setCurrentTheme@resource://gre/modules/LightweightThemeManager.jsm:707:3
set currentTheme@resource://gre/modules/LightweightThemeManager.jsm:157:12
updateDevtoolsThemeAttribute@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:167:46
observe@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:184:13
SetPref@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:37:14
createThemeOption/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:283:9
EventListener.handleEvent*createThemeOption@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:282:7
setupThemeList@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:298:28
OptionsPanel.prototype.open<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:92:5
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:311:39
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
_handleResultValue@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:387:7
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:319:13
TaskImpl@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:273:3
asyncFunction@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:247:14
onLoad@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox.js:1476:19


1.1ms uninterruptible reflow at forceStyle@chrome://devtools/content/shared/theme-switching.js:44:9

Here's the stack:

forceStyle@chrome://devtools/content/shared/theme-switching.js:44:9
switchTheme@chrome://devtools/content/shared/theme-switching.js:132:9
handlePrefChange@chrome://devtools/content/shared/theme-switching.js:170:5
SetPref@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:37:14
createThemeOption/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:283:9
waitForSyncCallback@resource://services-common/async.js:98:7
makeSpinningCallback/callback.wait@resource://services-common/async.js:168:27
_handlerListener@resource://services-sync/addonsreconciler.js:633:9
onEnabled@resource://services-sync/addonsreconciler.js:645:5
callAddonListeners@resource://gre/modules/AddonManager.jsm:1693:11
callAddonListeners@resource://gre/modules/AddonManager.jsm:3160:5
addonChanged@resource://gre/modules/LightweightThemeManager.jsm:419:9
callProvider@resource://gre/modules/AddonManager.jsm:268:12
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:1741:7
notifyAddonChanged@resource://gre/modules/AddonManager.jsm:3141:5
_setCurrentTheme@resource://gre/modules/LightweightThemeManager.jsm:707:3
set currentTheme@resource://gre/modules/LightweightThemeManager.jsm:157:12
updateDevtoolsThemeAttribute@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:167:46
observe@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js:184:13
SetPref@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:37:14
createThemeOption/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:283:9
EventListener.handleEvent*createThemeOption@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:282:7
setupThemeList@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:298:28
OptionsPanel.prototype.open<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox-options.js:92:5
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:311:39
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
_handleResultValue@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:387:7
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:319:13
TaskImpl@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:273:3
asyncFunction@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:247:14
onLoad@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/toolbox.js:1476:19
Flags: qe-verify?
Priority: -- → P2
Please correct if this isn't the right component! Thank you.
Component: Untriaged → Toolbars and Customization
So, the bottom stack is devtools. I'm moving this bug there, as it's the most actionable of the 3 stacks in comment #0.

The other two stacks don't make sense to me. _onLazyResize isn't called from add-on enabled handlers, only when the window resizes, which shouldn't be happening here - though it might be worth checking that this isn't caused by the content area changing size, triggering a resize event there, and that bubbling up to the overflow toolbar listener, in non-e10s (but that shouldn't happen in e10s - though maybe devtools use same-process frames that would also cause this?). Either way, the stack seems to be missing all that.

The top stack seems incomplete, as there's nothing in waitForSyncCallback that does any style or layout flushing that I can see. Mike, are you aware of issues with stacks as produced by the add-on?
Blocks: compact-themes
No longer blocks: photon-performance-triage
Component: Toolbars and Customization → Developer Tools
Flags: needinfo?(mconley)
Whiteboard: [ohnoreflow][qf][photon-performance] → [ohnoreflow][qf-][photon-performance]
I think we're seeing the result of nested event loops in JS.

For the second stack, I suspect we're in the midst of running a nested event loop in our Sync code, and while that happens, the window has been resized. Resize events are debounced using DeferredTask, and so we're kicking that DeferredTask off with a timer, while running the nested event loop.

I'm guessing this is probably where the reflow is occurring there: http://searchfox.org/mozilla-central/rev/ce5ccb6a8ca803271c946ccb8b43b7e7d8b64e7a/browser/components/customizableui/CustomizableUI.jsm#4251

The top stack is us just spinning a nested event loop in JS, I believe - and then some native code is probably causing a layout flush.
Flags: needinfo?(mconley)
Priority: P2 → P3
Whiteboard: [ohnoreflow][qf-][photon-performance] → [ohnoreflow][qf-][reserve-photon-performance]
Flags: qe-verify? → qe-verify-
Priority: P3 → P4
Keywords: perf
Whiteboard: [ohnoreflow][qf-][reserve-photon-performance] → [ohnoreflow][qf-][fxperf]
I'm not completely sure what the code at https://searchfox.org/mozilla-central/rev/877c99c523a054419ec964d4dfb3f0cadac9d497/devtools/client/shared/theme-switching.js#36-50 is trying to do, but I'm guessing that it wants to invalidate the whole style tree.

I don't see why any JS code would have to do that by hand, so I suspect it's working around a bug... that may no longer exist.

Anyway, low priority for fxperf work, but may be a low hanging fruit for devtools perf work.
Whiteboard: [ohnoreflow][qf-][fxperf] → [ohnoreflow][qf-][fxperf:p5]
(In reply to Florian Quèze [:florian] from comment #4)
> I don't see why any JS code would have to do that by hand, so I suspect it's
> working around a bug... that may no longer exist.
> 
> Anyway, low priority for fxperf work, but may be a low hanging fruit for
> devtools perf work.

I believe it's trying to ensure the fixed-size scrollbars are replaced by overlay scrollbars (or vice versa), and perhaps that required this hack at some stage...  It was first added by bug 851546 ~5 years ago, but there's no clear reason given in that bug that I can see.

Seems worth trying to remove it and checking the scrollbars for issues.
Product: Firefox → DevTools
Performance Impact: --- → -
Whiteboard: [ohnoreflow][qf-][fxperf:p5] → [ohnoreflow][fxperf:p5]
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.