Open Bug 1605949 Opened 5 years ago Updated 2 years ago

Intermittent devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | Test timed out -

Categories

(DevTools :: Inspector, defect, P5)

Product:
DevTools
Component:
Inspector
Type:
defect

Tracking

(Not tracked)

Status:
ASSIGNED

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=282604796&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OE448HUcQoW6c20UcSBuBw/runs/0/artifacts/public/logs/live_backing.log

[task 2019-12-25T18:22:56.930Z] 18:22:56 INFO - TEST-INFO | started process screentopng
[task 2019-12-25T18:22:57.285Z] 18:22:57 INFO - TEST-INFO | screentopng: exit 0
[task 2019-12-25T18:22:57.286Z] 18:22:57 INFO - Buffered messages logged at 18:21:26
[task 2019-12-25T18:22:57.286Z] 18:22:57 INFO - Entering test bound
[task 2019-12-25T18:22:57.286Z] 18:22:57 INFO - Adding a new tab with URL: data:text/html;charset=utf-8,%0A%20%20%3Cstyle%20type%3D'text%2Fcss'%3E%0A%20%20%20%20%23grid%20%7B%0A%20%20%20%20%20%20display%3A%20grid%3B%0A%20%20%20%20%7D%0A%20%20%3C%2Fstyle%3E%0A%20%20%3Cdiv%20id%3D%22grid%22%3E%0A%20%20%20%20%3Cdiv%20id%3D%22cell1%22%3Ecell1%3C%2Fdiv%3E%0A%20%20%20%20%3Cdiv%20id%3D%22cell2%22%3Ecell2%3C%2Fdiv%3E%0A%20%20%3C%2Fdiv%3E%0A
[task 2019-12-25T18:22:57.287Z] 18:22:57 INFO - Buffered messages logged at 18:21:27
[task 2019-12-25T18:22:57.287Z] 18:22:57 INFO - Tab added and finished loading
[task 2019-12-25T18:22:57.287Z] 18:22:57 INFO - Opening the inspector
[task 2019-12-25T18:22:57.288Z] 18:22:57 INFO - Opening the toolbox
[task 2019-12-25T18:22:57.288Z] 18:22:57 INFO - Buffered messages logged at 18:21:28
[task 2019-12-25T18:22:57.289Z] 18:22:57 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2019-12-25T18:22:57.290Z] 18:22:57 INFO - Buffered messages logged at 18:21:29
[task 2019-12-25T18:22:57.291Z] 18:22:57 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2019-12-25T18:22:57.292Z] 18:22:57 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2019-12-25T18:22:57.293Z] 18:22:57 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2019-12-25T18:22:57.294Z] 18:22:57 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2019-12-25T18:22:57.294Z] 18:22:57 INFO - Toolbox opened and focused
[task 2019-12-25T18:22:57.294Z] 18:22:57 INFO - Selecting the layoutview sidebar
[task 2019-12-25T18:22:57.295Z] 18:22:57 INFO - Selecting the node for '#grid'
[task 2019-12-25T18:22:57.296Z] 18:22:57 INFO - Buffered messages logged at 18:21:30
[task 2019-12-25T18:22:57.296Z] 18:22:57 INFO - Checking the initial state of the Grid Inspector.
[task 2019-12-25T18:22:57.297Z] 18:22:57 INFO - TEST-PASS | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | One grid container is listed. -
[task 2019-12-25T18:22:57.298Z] 18:22:57 INFO - TEST-PASS | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | No CSS grid highlighter is shown. -
[task 2019-12-25T18:22:57.299Z] 18:22:57 INFO - Toggling ON the CSS grid highlighter from the layout panel.
[task 2019-12-25T18:22:57.300Z] 18:22:57 INFO - Waiting for state predicate "state => state.grids.length == 1 && state.grids[0].highlighted"
[task 2019-12-25T18:22:57.301Z] 18:22:57 INFO - Found state predicate "state => state.grids.length == 1 && state.grids[0].highlighted"
[task 2019-12-25T18:22:57.301Z] 18:22:57 INFO - Checking the CSS grid highlighter is created.
[task 2019-12-25T18:22:57.301Z] 18:22:57 INFO - TEST-PASS | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | CSS grid highlighter is shown. -
[task 2019-12-25T18:22:57.301Z] 18:22:57 INFO - Removing the #grid container in the content page.
[task 2019-12-25T18:22:57.302Z] 18:22:57 INFO - Waiting for state predicate "state => state.grids.length == 0"
[task 2019-12-25T18:22:57.302Z] 18:22:57 INFO - Buffered messages finished
[task 2019-12-25T18:22:57.302Z] 18:22:57 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | Test timed out -
[task 2019-12-25T18:22:57.323Z] 18:22:57 INFO - Removing tab.
[task 2019-12-25T18:22:57.324Z] 18:22:57 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2019-12-25T18:22:57.385Z] 18:22:57 INFO - Got event: 'TabClose' on [object XULElement].
[task 2019-12-25T18:22:57.433Z] 18:22:57 INFO - Tab removed and finished closing

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=343793223&repo=mozilla-esr78&lineNumber=19917

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Update:
There have been 26 failures within the last 7 days:
• 3 failures on Linux 18.04 x64 WebRender asan opt
• 15 failures on Linux 18.04 x64 WebRender opt
• 2 failures on Linux 18.04 x64 WebRender Shippable opt
• 2 failures on OS X 10.15 WebRender debug
• 4 failures on Windows 10 x64 2004 WebRender opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=370460509&repo=autoland&lineNumber=5810

[task 2022-03-09T22:30:24.872Z] 22:30:24     INFO - TEST-PASS | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | CSS grid highlighter is shown. - 
[task 2022-03-09T22:30:24.873Z] 22:30:24     INFO - Removing the #grid container in the content page.
[task 2022-03-09T22:30:24.873Z] 22:30:24     INFO - Waiting for state predicate "state => state.grids.length == 0"
[task 2022-03-09T22:30:24.880Z] 22:30:24     INFO - Buffered messages finished
[task 2022-03-09T22:30:24.881Z] 22:30:24     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | Test timed out - 
[task 2022-03-09T22:30:24.881Z] 22:30:24     INFO - Removing tab.
[task 2022-03-09T22:30:24.882Z] 22:30:24     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-03-09T22:30:24.888Z] 22:30:24     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-03-09T22:30:24.888Z] 22:30:24     INFO - Tab removed and finished closing
[task 2022-03-09T22:30:24.889Z] 22:30:24     INFO - GECKO(4847) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-03-09T22:30:24.890Z] 22:30:24     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-03-09T22:30:24.894Z] 22:30:24     INFO - TEST-PASS | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2022-03-09T22:30:24.895Z] 22:30:24     INFO - GECKO(4847) | MEMORY STAT | vsize 3391MB | residentFast 528MB | heapAllocated 251MB
[task 2022-03-09T22:30:24.896Z] 22:30:24     INFO - TEST-OK | devtools/client/inspector/grids/test/browser_grids_grid-list-on-mutation-element-removed.js | took 45309ms
[task 2022-03-09T22:30:24.896Z] 22:30:24     INFO - checking window state
[task 2022-03-09T22:30:24.897Z] 22:30:24     INFO - TEST-START | devtools/client/inspector/grids/test/browser_grids_grid-list-on-target-added-removed.js
Whiteboard: [stockwell needswork:owner]

Hi Julian! Can you please take a look at this? Maybe you could help us assign it to someone.
Thank you!

Flags: needinfo?(jdescottes)

From what I can tell, this seems to be an issue/race condition with the implementation, not simply with the test.
Looking at the failure screenshot, the test hangs because we keep a grid item in the layout panel, but it looks buggy. The representation of the dom element is just { }.

So I am guessing we have two events which come in a different order when the test fails. I think that adding delays in the test will also not help, but I'll give it a try before moving forward with the investigation, this would help to confirm a race in the implementation.

Assignee: nobody → jdescottes
Status: REOPENED → ASSIGNED

Interesting to note that a similar test was already disabled for timeouts 3 years ago: Bug 1557326

Flags: needinfo?(jdescottes)
See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1557326

Slow progress here, it reproduces very rarely on try so it's hard to get confident about any change I am doing.
For now I suspect a race in the following method:
https://searchfox.org/mozilla-central/rev/980b50947e2a855c92f2df74209dadad3ee4d119/devtools/client/inspector/grids/grid-inspector.js#319-436

It contains a lot of try/catch which just return without logging. And typically if a node is removed, the "rep" widget will turn into the { } we see in the screenshot and we expect the grid list to be updated and to remove the element. But if for any reason we fail to update and end in one of those try catches, the UI will indefinitely stay on this representation.

I am pushing with additional logs, as well as a "fix" attempt (resetting the grid display in case of an error, which might just be a bad idea):

Hopefully I can get some failures with the logs.

Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.