Closed Bug 1377326 Opened 3 years ago Closed 3 years ago

Style Editor takes minutes (!!) to load in Browser Toolbox, blocking UI

Categories

(DevTools :: Style Editor, defect)

defect
Not set
normal

Tracking

(firefox-esr52 unaffected, firefox54 unaffected, firefox55 unaffected, firefox56 fixed)

VERIFIED FIXED
Firefox 56
Tracking Status
firefox-esr52 --- unaffected
firefox54 --- unaffected
firefox55 --- unaffected
firefox56 --- fixed

People

(Reporter: jryans, Assigned: pbro)

References

(Blocks 1 open bug)

Details

(Keywords: regression)

Attachments

(1 file)

Gijs and I noticed that the Style Editor in the Browser Toolbox takes many minutes to load, and the entire Browser Toolbox UI is blocked until it finishes.

It slowly populates with one sheet after another until they have all finally loaded.

The problem area seems to be around `getMediaRules` in actors/stylesheets.js.  If I hack this to return an empty array, it starts up much more quickly.
This definitely used to work better. Not sure when it broke, but feels like in the last 2-4 weeks, tops. Might be useful to find a regression window.
I attempted this regression search, but then both the good and bad ends were "good" when it ran, and it also stop reproing in the original profile...

Seems like it's tied to some kind of state in the profile, but not sure what yet.
Okay, we've narrowed it down to some pref inside the chrome_debugger_profile, but now neither Gijs and I have a working repro case due to experimenting with fixes... :S
Ah, well, it appears to repro with a fresh profile, so at least there's that.
User Agent 	Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:56.0) Gecko/20100101 Firefox/56.0

I was able to reproduce the issue on the latest Nightly (56.0a1, Build ID 20170629030206). Narrowed the regression window to:

Last good revision: 196bfa86b5a63c20f7f6fdf3e30d9ff3d8839de3
First bad revision: 0d16a08bbcfa181535789a43856ef176cc9829c8
Pushlog:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=196bfa86b5a63c20f7f6fdf3e30d9ff3d8839de3&tochange=0d16a08bbcfa181535789a43856ef176cc9829c8

Kris, could you please take a look at this?
Blocks: 1370027
Has Regression Range: --- → yes
Flags: needinfo?(kmaglione+bmo)
Just a note that I am on macOS 10.12.5 and it looks like QA used Windows, so seems like a cross platform issue...  Perhaps it's related to the switch to Subprocess in bug 1370027?  (This would match Gijs' suspicion that the issue started happening a few weeks ago.)

Though, I am a bit confused about why profile state would matter for an issue with Subprocess...
Heh. So apparently the problem here is that the style editor dumps obscene numbers of exceptions:

*************************
console.error: 
  Message: TypeError: this._target.tab is undefined
  Stack:
    _updateMediaList/<@resource://devtools/client/styleeditor/StyleEditorUI.jsm:902:1
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:311:39
promise callback*_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
spawn@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:161:12
_updateMediaList@resource://devtools/client/styleeditor/StyleEditorUI.jsm:859:5
emit@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/event-emitter.js:194:13
_onMediaRulesChanged@resource://devtools/client/styleeditor/StyleSheetEditor.jsm:394:5
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
completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
onPacket/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1329:9
DevTools RDP*request@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1269:14
generateRequestMethods/</frontProto[name]@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1426:14
StyleSheetEditor@resource://devtools/client/styleeditor/StyleSheetEditor.jsm:129:5
StyleEditorPROC OUTPUT: UI.prototype._addStyleSheetEditor<@resource://devtools/client/styleeditor/StyleEditorUI.jsm:343:18
_run@resource://gre/modules/commonjs/PROC OUTPUT: toolkit/loader.js -> resource://devtools/shared/task.js:311:39
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
StyleEditorUI.prototype._addStyleSheet<@resource://devtools/client/styleeditor/StyleEditorUI.jsm:302:24
_run@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/task.js:311:39
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
StyleEditorUI.prototype._resetStyleSheetList<@resource://devtools/client/styleeditor/StyleEditorUI.jsm:251:15
_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
completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
onPacket/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1329:9
DevTools RDP*request@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1269:14
generateRequestMethods/</frontProto[name]@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1426:14
StyleEditorUI.prototype._addStyleSheet<@resource://devtools/client/styleeditor/StyleEditorUI.jsm:308:25
_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
completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
onPacket/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1329:9
DevTools RDP*request@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1269:14
generateRequestMethods/</frontProto[name]@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1426:14
promiseRest@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/fronts/string.js:35:16
promiseRest/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/fronts/string.js:37:27
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
completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
onPacket/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1329:9
DevTools RDP*request@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/protocol.js:1269:14

and it winds up blocking because we setup stdout as a pipe when launching the process, but don't read from it.
Flags: needinfo?(kmaglione+bmo)
Thank you Kris for the investigation in comment 7. Indeed there's a line of code in StyleEditorUI.jsm that causes errors:

if (this._target.tab.tagName == "tab") { ...

I don't understand why this is only causing problems now, but this likely has been failing since it was added (bug 1029371, in Firefox 46). Indeed, in the browser toolbox, the target is such that target.tab is undefined.
Hi Tim, I'm tempted to just write a patch that would replace the line mentioned in comment 8 with this:

if (this._target.tab) { ...

But I wanted to ask you first since you wrote that code. Why was checking for the tagName important? Any reason I should be aware of, or is the replacement ok?
Flags: needinfo?(ntim.bugs)
Assignee: nobody → pbrosset
Status: NEW → ASSIGNED
(In reply to Patrick Brosset <:pbro> from comment #9)
> Hi Tim, I'm tempted to just write a patch that would replace the line
> mentioned in comment 8 with this:
> 
> if (this._target.tab) { ...
> 
> But I wanted to ask you first since you wrote that code. Why was checking
> for the tagName important? Any reason I should be aware of, or is the
> replacement ok?

I can't remember why exactly I checked for tagName, but I recall it covered some specific cases. Maybe things have changed now, I have to test the patch and see.
Flags: needinfo?(ntim.bugs)
CCing Nihanth who came across this problem.
Here's a try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=07585d69685885f107064e945d8c0a5a8d194cac&group_state=expanded
So, all tests still seem to run. So if there were really specific cases that this case was covering, they're not being tested.
Tim, have you had time to test this?
I think I remember why I put tagName now, it was for Valence and other remote targets (FF for Android/Chrome/Safari/...). When I wrote the code, target.tab was available for those targets.
(In reply to Tim Nguyen :ntim from comment #14)
> I think I remember why I put tagName now, it was for Valence and other
> remote targets (FF for Android/Chrome/Safari/...). When I wrote the code,
> target.tab was available for those targets.

Hmm, I don't think I've seen a case remote debugging has a tab property...

It should be correct to test `target.isLocalTab` here (which effectively tests the tab property, similar to :pbro's patch), which is a little more clear about what's happening.  A comment about linking to RDM for local tabs sounds nice as well.
Comment on attachment 8883037 [details]
Bug 1377326 - Don't assume targets are tabs in style-editor media sidebar;

https://reviewboard.mozilla.org/r/154000/#review159666

::: devtools/client/styleeditor/StyleEditorUI.jsm:902
(Diff revision 1)
>          let cond = this._panelDoc.createElement("div");
>          cond.className = "media-rule-condition";
>          if (!rule.matches) {
>            cond.classList.add("media-condition-unmatched");
>          }
> -        if (this._target.tab.tagName == "tab") {
> +        if (this._target.tab) {

Can we use this._target.isLocalTab (thanks jryans for the suggestion) ?

This should be safe as this is what we actually use for the responsive mode command button check.

Feel free to land with this change done.
Attachment #8883037 - Flags: review?(ntim.bugs) → review+
(In reply to Kris Maglione [:kmag] from comment #7)
> Heh. So apparently the problem here is that the style editor dumps obscene
> numbers of exceptions

Let's try to simplify catching things like this in the future by piping Browser Toolbox logs to the parent so they reach the terminal.  I filed bug 1378480.
Pushed by pbrosset@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/592e5b42bb14
Don't assume targets are tabs in style-editor media sidebar; r=ntim
https://hg.mozilla.org/mozilla-central/rev/592e5b42bb14
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 56
User Agent 	Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:56.0) Gecko/20100101 Firefox/56.0
Build ID 	20170711030203

The issue is verified fixed on the latest Nightly 56.0a1 (2017-07-11) on the following OSes:
- Windows 10 x64
- Mac 10.12
- Ubuntu 14.04 x64
Status: RESOLVED → VERIFIED
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.