Intermittent browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Test timed out -
Categories
(WebExtensions :: Untriaged, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Blocks 1 open bug)
Details
(Keywords: intermittent-failure, regression)
Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=269896916&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/PJppkHeuSHyrFODFzMsw8g/runs/0/artifacts/public/logs/live_backing.log
[task 2019-10-05T11:06:49.682Z] 11:06:49 INFO - TEST-START | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js
[task 2019-10-05T11:07:34.705Z] 11:07:34 INFO - TEST-INFO | started process screenshot
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - TEST-INFO | screenshot: exit 0
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - Buffered messages logged at 11:06:49
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - Entering test bound test_devtools_inspectedWindow_tabId
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - Extension loaded
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - Console message: Warning: attempting to write 10412 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2019-10-05T11:07:34.774Z] 11:07:34 INFO - Buffered messages logged at 11:06:50
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | No devtools APIs should be available in the background page - Expected: undefined, Actual: undefined -
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - Registering testBlankPanel tool to the developer tools
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | The runtime.getBackgroundPage
API method should be missing in a devtools_page context - Expected: undefined, Actual: undefined -
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - Developer toolbox opened on panel "testBlankPanel" for target {}
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Got the expected tabId from devtool.inspectedWindow.tabId -
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Got the expected tabId from devtool.inspectedWindow.tabId called in a devtool_page iframe -
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - Developer toolbox closed for target {}
[task 2019-10-05T11:07:34.775Z] 11:07:34 INFO - Leaving test bound test_devtools_inspectedWindow_tabId
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Entering test bound test_devtools_inspectedWindow_eval
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Buffered messages logged at 11:06:51
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Extension loaded
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Console message: Warning: attempting to write 10492 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Developer toolbox opened on panel "testBlankPanel" for target {}
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - test inspectedWindow.eval with {"args":["window.location.href"],"expectedResults":{"evalResult":"http://mochi.test:8888/"}}
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - Buffered messages finished
[task 2019-10-05T11:07:34.776Z] 11:07:34 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Test timed out -
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | no tasks awaiting on messages - Got ["inspectedWindow-eval-result"], expected []
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - Stack trace:
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:test_is:1595
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:31
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:nextTest:860
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1471
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - setTimeout handlerchrome://mochikit/content/browser-test.js:Tester_execTest:1418
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1213
[task 2019-10-05T11:07:34.781Z] 11:07:34 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:805
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Extension left running at test shutdown -
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - Stack trace:
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:test_ok:1580
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:nextTest:860
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1471
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - setTimeout handlerchrome://mochikit/content/browser-test.js:Tester_execTest:1418
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1213
[task 2019-10-05T11:07:34.782Z] 11:07:34 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:805
[task 2019-10-05T11:07:34.873Z] 11:07:34 INFO - GECKO(10824) | MEMORY STAT | vsize 2104628MB | vsizeMaxContiguous 65447301MB | residentFast 433MB | heapAllocated 138MB
[task 2019-10-05T11:07:34.873Z] 11:07:34 INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | took 45197ms
[task 2019-10-05T11:07:34.873Z] 11:07:34 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-05T11:07:34.873Z] 11:07:34 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Found a tab after previous test timed out: http://mochi.test:8888/ -
[task 2019-10-05T11:07:34.915Z] 11:07:34 INFO - checking window state
[task 2019-10-05T11:07:35.159Z] 11:07:35 INFO - TEST-START | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow_eval_bindings.js
[task 2019-10-05T11:07:36.100Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2019-10-05T11:07:36.100Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2019-10-05T11:07:36.125Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2019-10-05T11:07:36.135Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2019-10-05T11:07:36.153Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2019-10-05T11:07:36.214Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2019-10-05T11:07:36.224Z] 11:07:36 INFO - GECKO(10824) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2019-10-05T11:07:37.218Z] 11:07:37 INFO - GECKO(10824) | MEMORY STAT | vsize 2104631MB | vsizeMaxContiguous 65447301MB | residentFast 446MB | heapAllocated 167MB
[task 2019-10-05T11:07:37.218Z] 11:07:37 INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow_eval_bindings.js | took 2064ms
Comment hidden (Intermittent Failures Robot) |
Comment 2•6 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 3•6 years ago
|
||
New failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=274789264&repo=autoland&lineNumber=3675
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 7•6 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 8•5 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 15•5 years ago
|
||
There are 20 total failures in the last 7 days.
debug: windows10-64, windows10-64-qr, linux1804-64, windows7-32
opt: windows10-64-shippable, macosx1014-64-shippable, windows7-32-shippable
asan: windows10-64
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=300136641&repo=autoland&lineNumber=15731
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 18•5 years ago
|
||
Seems we had a blip for a couple weeks, then back to normal, but ni? luca incase he sees something obvious.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 21•5 years ago
|
||
(In reply to Shane Caraveo (:mixedpuppy) (on PTO) from comment #18)
Seems we had a blip for a couple weeks, then back to normal, but ni? luca incase he sees something obvious.
I looked to the last failures available and I can't see anything useful in the failure logs, the test was calling browser.devtools.inspectedWindow.eval and it did fail for timeout while waiting for the "inspectedWindow-eval-result" message, but then it seems that we got that message when the test was exiting due to the timeout failure:
[task 2020-06-09T20:36:09.359Z] 20:36:09 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | Test timed out -
[task 2020-06-09T20:36:09.359Z] 20:36:09 INFO - GECKO(1252) | [Parent 1252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fefaa43f400 == 8 [pid = 1252] [id = {cb96b6be-2228-48dd-aec7-5fda7f23095d}]
[task 2020-06-09T20:36:09.359Z] 20:36:09 INFO - GECKO(1252) | [Parent 1252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7fefadca9de0) [pid = 1252] [serial = 163] [outer = (nil)]
[task 2020-06-09T20:36:09.360Z] 20:36:09 INFO - GECKO(1252) | [Parent 1252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7fefaa446000) [pid = 1252] [serial = 164] [outer = 0x7fefadca9de0]
[task 2020-06-09T20:36:09.421Z] 20:36:09 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-06-09T20:36:09.422Z] 20:36:09 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_inspectedWindow.js | no tasks awaiting on messages - Got ["inspectedWindow-eval-result"], expected []
It may have been related to some changes happened on the devtools side (maybe some of the fission-related changes) that may have started to trigger the intermittent failure, and then some additional changes may have fixed it.
Unfortunately I can't currently see any other detail in the failure logs that would help me to identify exactly what changes may have introduced and then fixed the higher intermittency.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Updated•3 years ago
|
Description
•