Intermittent devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | Test timed out -
Categories
(DevTools :: Inspector: Rules, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, Whiteboard: [retriggered])
Filed by: dluca [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=219795177&repo=autoland https://queue.taskcluster.net/v1/task/O7aVa20NSTu4AdJOdOSXoA/runs/0/artifacts/public/logs/live_backing.log INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | Has UA rules - 16:28:01 INFO - Selecting the node for 'input[type=number]' 16:28:01 INFO - Buffered messages logged at 16:25:46 16:28:01 INFO - Longer timeout required, waiting longer... Remaining timeouts: 3 16:28:01 INFO - Buffered messages logged at 16:26:18 16:28:01 INFO - Console message: [JavaScript Error: "getScreenshot(http://example.com/browser/devtools/client/inspector/rules/test/doc_urls_clickable.html) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 45}] 16:28:01 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:45:7 16:28:01 INFO - async*maybeCacheScreenshot@resource://activity-stream/lib/Screenshots.jsm:98:32 16:28:01 INFO - async*_fetchScreenshot@resource://activity-stream/lib/TopSitesFeed.jsm:439:11 16:28:01 INFO - async*_fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:427:11 16:28:01 INFO - async*getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:329:11 16:28:01 INFO - async*refresh@resource://activity-stream/lib/TopSitesFeed.jsm:352:25 16:28:01 INFO - async*onAction@resource://activity-stream/lib/TopSitesFeed.jsm:652:9 16:28:01 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:51:11 16:28:01 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54 16:28:01 INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:16:41 16:28:01 INFO - notify@resource://gre/modules/Timer.jsm:42:7 16:28:01 INFO - 16:28:01 INFO - Console message: [JavaScript Error: "Unknown collection "main/tippytop"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 261}] 16:28:01 INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:261:13 16:28:01 INFO - async*get@resource://services-settings/RemoteSettingsClient.jsm:230:17 16:28:01 INFO - async*getSite@resource://activity-stream/lib/FaviconFeed.jsm:156:25 16:28:01 INFO - async*fetchIcon@resource://activity-stream/lib/FaviconFeed.jsm:130:24 16:28:01 INFO - async*onAction@resource://activity-stream/lib/FaviconFeed.jsm:180:9 16:28:01 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:51:11 16:28:01 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54 16:28:01 INFO - _requestRichIcon@resource://activity-stream/lib/TopSitesFeed.jsm:460:5 16:28:01 INFO - _fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:424:5 16:28:01 INFO - async*getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:329:11 16:28:01 INFO - async*refresh@resource://activity-stream/lib/TopSitesFeed.jsm:352:25 16:28:01 INFO - async*onAction@resource://activity-stream/lib/TopSitesFeed.jsm:652:9 16:28:01 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:51:11 16:28:01 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54 16:28:01 INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:16:41 16:28:01 INFO - notify@resource://gre/modules/Timer.jsm:42:7 16:28:01 INFO - 16:28:01 INFO - Buffered messages logged at 16:26:31 16:28:01 INFO - Longer timeout required, waiting longer... Remaining timeouts: 2 16:28:01 INFO - Buffered messages logged at 16:27:16 16:28:01 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1 16:28:01 INFO - Buffered messages finished 16:28:01 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | Test timed out - 16:28:01 INFO - Not taking screenshot here: see the one that was previously logged 16:28:01 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | Uncaught exception received from previously timed out test - at resource://devtools/shared/protocol.js:1320 - Error: Connection closed, pending request to server1.conn216.child1/domwalker26, type querySelector failed 16:28:01 INFO - 16:28:01 INFO - Request stack: 16:28:01 INFO - request@resource://devtools/shared/protocol.js:1407:14 16:28:01 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol.js:1531:14 16:28:01 INFO - querySelector@resource://devtools/shared/fronts/inspector.js:161:12 16:28:01 INFO - getNodeFront@chrome://mochitests/content/browser/devtools/client/inspector/test/shared-head.js:232:10 16:28:01 INFO - selectNode@chrome://mochitests/content/browser/devtools/client/inspector/test/shared-head.js:247:27 16:28:01 INFO - async*userAgentStylesVisible@chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js:109:11 16:28:01 INFO - async*@chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js:70:9 16:28:01 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1106:34 16:28:01 INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1097:16 16:28:01 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:995:9 16:28:01 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59 16:28:01 INFO - 16:28:01 INFO - Stack trace: 16:28:01 INFO - destroy@resource://devtools/shared/protocol.js:1320:23 16:28:01 INFO - destroy@resource://devtools/shared/fronts/inspector.js:60:5 16:28:01 INFO - destroy@resource://devtools/shared/protocol.js:947:9 16:28:01 INFO - destroy@resource://devtools/shared/protocol.js:1322:5 16:28:01 INFO - destroy@resource://devtools/shared/fronts/inspector.js:492:5 16:28:01 INFO - destroyInspector/this._destroyingInspector<@resource://devtools/client/framework/toolbox.js:2799:13 16:28:01 INFO - Async*destroyInspector@resource://devtools/client/framework/toolbox.js:2788:40 16:28:01 INFO - _destroyToolbox@resource://devtools/client/framework/toolbox.js:2906:22 16:28:01 INFO - async*destroy@resource://devtools/client/framework/toolbox.js:2836:23 16:28:01 INFO - closeToolbox@resource://devtools/client/framework/devtools.js:594:11 16:28:01 INFO - async*closeTabAndToolbox@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:453:11 16:28:01 INFO - async*cleanup@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:137:11 16:28:01 INFO - async*nextTest@chrome://mochikit/content/browser-test.js:705:30 16:28:01 INFO - async*timeoutFn@chrome://mochikit/content/browser-test.js:1203:9 16:28:01 INFO - setTimeout handler*SimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:684:12 16:28:01 INFO - timeoutFn@chrome://mochikit/content/browser-test.js:1181:13 16:28:01 INFO - setTimeout handler*SimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:684:12 16:28:01 INFO - timeoutFn@chrome://mochikit/content/browser-test.js:1181:13 16:28:01 INFO - setTimeout handler*SimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:684:12 16:28:01 INFO - timeoutFn@chrome://mochikit/content/browser-test.js:1181:13 16:28:01 INFO - setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1165:9 16:28:01 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:995:9 16:28:01 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59 16:28:05 INFO - Removing tab. 16:28:05 INFO - Waiting for event: 'TabClose' on [object XULElement]. 16:28:05 INFO - Got event: 'TabClose' on [object XULElement]. 16:28:05 INFO - Tab removed and finished closing 16:28:05 INFO - GECKO(1096) | MEMORY STAT | vsize 1801MB | vsizeMaxContiguous 52MB | residentFast 892MB | heapAllocated 375MB 16:28:05 INFO - TEST-OK | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | took 183719ms 16:28:05 INFO - checking window state 16:28:05 INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_user-property-reset.js
Comment 1•6 years ago
|
||
This seems to have started when Bug 1516408 landed here: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=success%2Ctestfailed&searchStr=windows%2C7%2Cpgo%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows7-32-pgo%2Fopt-mochitest-devtools-chrome-e10s-8%2Cm-e10s%28dt8%29&tochange=13d9e2a48dbb3cc3d4e8a58a918a1cef129156d3&group_state=expanded&fromchange=a29627aa1ef5977bff1e93dcd150a274cfe79e15&selectedJob=220246392 Julian, could you please take a look over this? Thank you.
Comment hidden (Intermittent Failures Robot) |
Comment 3•6 years ago
|
||
It's unlikely that my patches had impact there. I did some more retriggers on the previous changeset and it seems to already happen there: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=success%2Ctestfailed&searchStr=windows%2C7%2Cpgo%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows7-32-pgo%2Fopt-mochitest-devtools-chrome-e10s-8%2Cm-e10s%28dt8%29&tochange=13d9e2a48dbb3cc3d4e8a58a918a1cef129156d3&group_state=expanded&fromchange=a29627aa1ef5977bff1e93dcd150a274cfe79e15&selectedJob=220312734 The test is repeated for a variety of DOM elements and doesn't always fail for the same element. However it always seems to fail while waiting for a call to getApplied: let entries = await inspector.pageStyle.getApplied( inspector.selection.nodeFront, { inherited: true, matchedSelectors: true, filter: filter, } ); (https://searchfox.org/mozilla-central/rev/f8de61826903996f6bdf41b11a2844dd59ac144f/devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js#154) When the test times out, the logs report that this getApplied request failed. But they also report that a getUsedFontFaces failed: console.error: "Could not get the list of font families" (new Error("Connection closed, pending request to server1.conn216.child1/pagestyle28, type getUsedFontFaces failed This other request comes from the creation of the text-property-editor: this.rule.elementStyle.getUsedFontFamilies().then(families => { // ... }).catch(e => console.error("Could not get the list of font families", e)); (https://searchfox.org/mozilla-central/rev/f8de61826903996f6bdf41b11a2844dd59ac144f/devtools/client/inspector/rules/views/text-property-editor.js#436) And this happens when we selected the node in the test, right before calling getApplied: await selectNode(data.selector, inspector); await compareAppliedStylesWithUI(inspector, view); (https://searchfox.org/mozilla-central/rev/f8de61826903996f6bdf41b11a2844dd59ac144f/devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js#141) The inspector is not waiting for this server-side call before firing the "inspector-updated" event which we are expected for after selecting a node in tests. So both requests getUsedFontFaces and getApplied are probably fired in parallel. I have no idea why the requests fail at the moment, not even sure if the fact that they are both triggered at the same time is related to the issue.
Comment 4•6 years ago
|
||
Julian, thanks for the input on this and yeah it looks like this starts with the push just before yours, sorry about that. https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=success%2Ctestfailed&searchStr=windows%2C7%2Cpgo%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows7-32-pgo%2Fopt-mochitest-devtools-chrome-e10s-8%2Cm-e10s%28dt8%29&tochange=13d9e2a48dbb3cc3d4e8a58a918a1cef129156d3&fromchange=a29627aa1ef5977bff1e93dcd150a274cfe79e15&group_state=expanded&selectedJob=220312735
This has toned down and on the 7th (1 failure) and 8th there are almost no failures so maybe working on another bug fixed this. Let's revisit if the failure rate increases.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 7•6 years ago
|
||
Comment 8•6 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=236274214&repo=mozilla-inbound&lineNumber=4695
01:40:06 INFO - Buffered messages logged at 01:39:21
01:40:06 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
01:40:06 INFO - Buffered messages finished
01:40:06 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | Test timed out -
01:40:06 INFO - Removing tab.
01:40:06 INFO - Waiting for event: 'TabClose' on [object XULElement].
01:40:06 INFO - Got event: 'TabClose' on [object XULElement].
01:40:06 INFO - Tab removed and finished closing
01:40:06 INFO - GECKO(3540) | MEMORY STAT | vsize 1517MB | vsizeMaxContiguous 122MB | residentFast 472MB | heapAllocated 81MB
01:40:06 INFO - TEST-OK | devtools/client/inspector/rules/test/browser_rules_user-agent-styles.js | took 180221ms
01:40:06 INFO - checking window state
01:40:06 INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_user-property-reset.js
01:40:06 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
01:40:07 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
01:40:07 INFO - Not taking screenshot here: see the one that was previously logged
01:40:07 INFO - Buffered messages logged at 01:40:06
01:40:07 INFO - Entering test bound
01:40:07 INFO - Adding a new tab with URL: data:text/html;charset=utf-8,%0A%20%20%3Cp%20id%3D'id1'%20style%3D'width%3A200px%3B'%3Eelement%201%3C%2Fp%3E%0A%20%20%3Cp%20id%3D'id2'%20style%3D'width%3A100px%3B'%3Eelement%202%3C%2Fp%3E%0A
01:40:07 INFO - Tab added and finished loading
01:40:07 INFO - Loading the helper frame script chrome://mochitests/content/browser/devtools/client/inspector/rules/test/doc_frame_script.js
01:40:07 INFO - Opening the inspector
01:40:07 INFO - Opening the toolbox
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Buffered messages logged at 01:40:07
01:40:07 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
01:40:07 INFO - Toolbox opened and focused
Comment hidden (Intermittent Failures Robot) |
Comment 10•5 years ago
|
||
Comment 11•5 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 13•5 years ago
|
||
Comment 14•4 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=303559022&repo=mozilla-beta&lineNumber=6308
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Description
•