Closed Bug 1386410 Opened 6 years ago Closed 6 years ago

Perma failure when 56 merges to beta in devtools/client/framework/test/browser_toolbox_custom_host.js | Test timed out


(DevTools :: Console, defect, P1)



(firefox56 verified disabled, firefox57 fixed)

Firefox 57
57.3 - Sep 19
Tracking Status
firefox56 --- verified disabled
firefox57 --- fixed


(Reporter: aryx, Assigned: bgrins)



(Keywords: intermittent-failure, Whiteboard: [reserve-console-html])


(1 file)

Merge day is tomorrow (August 2nd)

Failure log:
[task 2017-07-31T21:22:25.975173Z] 21:22:25     INFO - TEST-START | devtools/client/framework/test/browser_toolbox_custom_host.js
[task 2017-07-31T21:23:11.012289Z] 21:23:11     INFO - TEST-INFO | started process screentopng
[task 2017-07-31T21:23:11.417540Z] 21:23:11     INFO - TEST-INFO | screentopng: exit 0
[task 2017-07-31T21:23:11.418779Z] 21:23:11     INFO - Buffered messages logged at 21:22:25
[task 2017-07-31T21:23:11.418921Z] 21:23:11     INFO - Adding a new tab with URL: data:text/html,test custom host
[task 2017-07-31T21:23:11.419831Z] 21:23:11     INFO - Buffered messages logged at 21:22:26
[task 2017-07-31T21:23:11.421035Z] 21:23:11     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html,test%20custom%20host" line: 0}]
[task 2017-07-31T21:23:11.422582Z] 21:23:11     INFO - Tab added and finished loading
[task 2017-07-31T21:23:11.424194Z] 21:23:11     INFO - Console message: [JavaScript Warning: "Unknown property ‘user-select’.  Declaration dropped." {file: "resource://devtools/client/shared/components/reps/reps.css" line: 218 column: 13 source: "  user-select: none;"}]
[task 2017-07-31T21:23:11.425739Z] 21:23:11     INFO - onMessage: {"name":"toolbox-title","data":{"value":"Developer Tools - data:text/html,test custom host - data:text/html,test%20custom%20host"}}
[task 2017-07-31T21:23:11.427385Z] 21:23:11     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_custom_host.js | Toolbox is included in browser.xul - 
[task 2017-07-31T21:23:11.429368Z] 21:23:11     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_custom_host.js | Toolbox is in the custom iframe - 
[task 2017-07-31T21:23:11.431258Z] 21:23:11     INFO - onMessage: {"name":"toolbox-close"}
[task 2017-07-31T21:23:11.433149Z] 21:23:11     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_custom_host.js | undefined assertion name - 
[task 2017-07-31T21:23:11.435066Z] 21:23:11     INFO - Buffered messages finished
[task 2017-07-31T21:23:11.436934Z] 21:23:11     INFO - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_custom_host.js | Test timed out -
Flags: needinfo?(bgrinstead)
Based on the assertions it looks like this is getting through to toolbox.destroy but that the promise returned there isn't being resolved
At one point I was able to reproduce this locally with the old frontend and `./mach mochitest devtools/client/framework/test/browser_toolbox_custom_host.js --run-until-failure`. AFAICT the destroy() function in the old console isn't resolving but as soon as I started to debug it the problem went away and I can't reproduce anymore.

This appears to be happening even without beta simulation, but just with the old console UI active:
Component: Developer Tools: Framework → Developer Tools: Console
Whiteboard: [console-html]
Not sure if it actually made a difference, but I've been able to reproduce again with:

  ./mach mochitest devtools/client/framework/test/browser_toolbox_custom_host.js --run-until-failure --setenv MOZ_CHAOSMODE=true

Also, it's a bit surprising but it appears that the webconsole panel does get destroyed successfully and that we are instead hanging inside the target destroy.
I've been able to reproduce most consistently on a clean m-c with:

  ./mach mochitest devtools/client/framework/test/browser_toolbox_custom_host.js --run-until-failure --setpref

Then right as the test window opens up and before the toolbox opens, switch focus away from the the browser and I can get the failure to happen most of the time.  So far I've narrowed this down to WebConsoleClient.detach not calling back onResponse which prevents the client from closing, which prevents the target from destroying, which prevents the toolbox from destroying.

The shutdown is something like: tabbrowserxml: removeTab -> target.js: destroy -> main.js: close -> webconsole/client.js: detach -> webconsole/client.js: stopListeners

And the call to stopListeners is not returning.  For whatever reason this only happens with the old frontend, and only in this particular shutdown sequence.

I will try to debug more today but I'm short on time, so leaving needinfos to some folks who may be able to help track it down tomorrow. Since this is blocking beta we could force the new webconsole on for this test to get past the error. But I think this is surfacing a race in the toolbox shutdown sequence that leaves things in a very bad state (similar to Bug 1383997).
Flags: needinfo?(poirot.alex)
Flags: needinfo?(nchevobbe)
Flags: needinfo?(bgrinstead)
If we need to unblock the beta merge I can make a patch that changes a pref for this test to use the new frontend and file a new bug for tracking down the toolbox shutdown race that this is surfacing.
Flags: needinfo?(aryx.bugmail)
Or we could skip the test in beta and re-enable it once we fix it
Whiteboard: [console-html] → [console-html] [triage]
Flags: qe-verify-
Priority: -- → P3
Whiteboard: [console-html] [triage] → [reserve-console-html]
Per IRC discussion with bgrins, disabled on Beta.
Flags: needinfo?(aryx.bugmail)
Still alive and well for 57 too.
Attached patch workaround patchSplinter Review
I've been using this patch to work around the issues at the moment. If we can't find anybody to prioritize investigating these issues, I'd rather just land it on m-c so I can stop juggling it in my patch queue.
Attachment #8902458 - Flags: feedback?(pbrosset)
Sure, let's skip the test for now. We still need to investigate the toolbox destroy race, but that can happen later in this bug or in another one.
Attachment #8902458 - Flags: feedback?(pbrosset) → feedback+
Pushed by
Skip browser_toolbox_custom_host.js for permafailing on uplift to Beta. r=bgrins, f=pbro
Thanks for the feedback, Patrick.
Flags: needinfo?(poirot.alex)
Flags: needinfo?(nchevobbe)
Keywords: leave-open
Assignee: nobody → ryanvm
Priority: P3 → P1
Target Milestone: --- → Firefox 57
I am very-much not the assignee of this bug nor is it sounding likely to be fixed during the 57 cycle.
Assignee: ryanvm → nobody
Target Milestone: Firefox 57 → ---
Priority: P1 → P3
I believe this can be unskipped now as of Bug 1397425. Would you please be able to check un-skipping this on a beta simulation to confirm?
Depends on: 1397425
Flags: needinfo?(ryanvm)
Looks that way indeed!
Assignee: nobody → bgrinstead
Flags: needinfo?(ryanvm)
Keywords: leave-open
Pushed by
Re-enable browser_toolbox_custom_host.js now that the new console frontend is riding the trains. r=bgrins
Iteration: --- → 57.3 - Sep 19
Priority: P3 → P1 - patch landed 4 hours ago
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 57
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.