Intermittent accessible/tests/mochitest/states/test_doc_busy.html | Test timed out.
Categories
(Core :: Disability Access APIs, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr68 | --- | unaffected |
firefox77 | --- | unaffected |
firefox78 | --- | unaffected |
firefox79 | --- | fixed |
firefox80 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: Jamie)
References
(Blocks 1 open bug, Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell fixed:patch])
Attachments
(4 files, 1 obsolete file)
Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=307218077&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KXszJSGORImBPH-sKM6Hyw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KXszJSGORImBPH-sKM6Hyw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
task 2020-06-23T09:14:54.563Z] 09:14:54 INFO - TEST-START | accessible/tests/mochitest/states/test_doc_busy.html
[task 2020-06-23T09:14:54.622Z] 09:14:54 INFO - GECKO(2904) | [3228, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp, line 1136
[task 2020-06-23T09:14:54.889Z] 09:14:54 INFO - GECKO(2904) | [3228, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040154 (NS_ERROR_FACTORY_NOT_REGISTERED): file /builds/worker/checkouts/gecko/netwerk/ipc/DocumentLoadListener.cpp, line 137
[task 2020-06-23T09:14:54.916Z] 09:14:54 INFO - GECKO(2904) | [3228, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp, line 4281
[task 2020-06-23T09:14:54.963Z] 09:14:54 INFO - GECKO(2904) | [3228, Main Thread] WARNING: NS_ENSURE_TRUE(root) failed: file /builds/worker/checkouts/gecko/layout/base/nsDocumentViewer.cpp, line 2921
[task 2020-06-23T09:16:48.034Z] 09:16:48 INFO - GECKO(2904) | [3228, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp, line 1360
[task 2020-06-23T09:18:48.043Z] 09:18:48 INFO - GECKO(2904) | [3228, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp, line 1360
[task 2020-06-23T09:19:54.631Z] 09:19:54 INFO - TEST-INFO | started process screenshot
[task 2020-06-23T09:19:54.698Z] 09:19:54 INFO - TEST-INFO | screenshot: exit 0
[task 2020-06-23T09:19:54.698Z] 09:19:54 INFO - Buffered messages logged at 09:14:54
[task 2020-06-23T09:19:54.698Z] 09:19:54 INFO - must wait for load
[task 2020-06-23T09:19:54.698Z] 09:19:54 INFO - Clicking link to trigger download
[task 2020-06-23T09:19:54.698Z] 09:19:54 INFO - Waiting for a11y busy events
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - Window opened, waiting for load event
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - Buffered messages logged at 09:14:55
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - Window loaded, checking if download prompt
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - Buffered messages finished
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - TEST-UNEXPECTED-FAIL | accessible/tests/mochitest/states/test_doc_busy.html | Test timed out.
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:409:16
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:138:22
[task 2020-06-23T09:19:54.699Z] 09:19:54 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:160:18
[task 2020-06-23T09:19:55.646Z] 09:19:55 INFO - GECKO(2904) | MEMORY STAT | vsize 897MB | vsizeMaxContiguous 322MB | residentFast 298MB | heapAllocated 95MB
[task 2020-06-23T09:19:55.647Z] 09:19:55 INFO - TEST-OK | accessible/tests/mochitest/states/test_doc_busy.html | took 301056ms
Comment 1•4 years ago
|
||
Jamie, this looks like a side effect the try run from bug 1626851 didn't catch. We might need help with what the screenshot shows, though.
Comment 2•4 years ago
|
||
tier 1 failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=307218077&repo=autoland&lineNumber=1315
Updated•4 years ago
|
Updated•4 years ago
|
Assignee | ||
Comment 4•4 years ago
|
||
Updated•4 years ago
|
Pushed by jteh@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ca1b88eb5c90 test_doc_busy.html: Handle the case where we get a load event for about:blank before the download prompt itself. r=MarcoZ
Comment 6•4 years ago
|
||
Set release status flags based on info from the regressing bug 1626851
Comment 7•4 years ago
|
||
bugherder |
Comment 8•4 years ago
•
|
||
Reopening since this is not fixed, retriggered on the push with the patch: :
https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedTaskRun=QQWqvCmDT8uJ-BPWhDrnQA.0&tochange=ca1b88eb5c905f0daf957e4a173137db04fae3c9&fromchange=d5231100ed240653511ce8baa89ba5a95595af77&searchStr=a11y
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Comment 9•4 years ago
|
||
Assignee | ||
Comment 10•4 years ago
|
||
I can't seem to repro this on try, so I guess we'll just have to land debug logging so we can catch it on central/autoland.
Comment 11•4 years ago
|
||
Pushed by mzehe@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/4025b7f21925 test_doc_busy.html: Log the window location so we can try to figure out why this is failing intermittently. r=MarcoZ
Comment hidden (Intermittent Failures Robot) |
Comment 13•4 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 16•4 years ago
|
||
It seems the window location isn't the issue here at all.
Rather, we never get the expected a11y events.
So, let's try to find out what events we do get.
Comment 17•4 years ago
|
||
Pushed by mzehe@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/0f09766b6b66 test_doc_busy.html: Log a11y events to help debug the intermittent timeout. r=MarcoZ
Comment hidden (Intermittent Failures Robot) |
Comment 19•4 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 21•4 years ago
|
||
From this log, it looks like busy events are just never fired for the document. There's some talk of the events being coalesced intermittently in bug 446469 and bug 569356, but I don't fully understand some of the discussion. If I understand bug 446469 comment 42 correctly, we previously didn't coalesce the events correctly, but there was concern that when we did, we (rightly) wouldn't get any busy events... which is what we're seeing now. But if that's the case, I don't understand why we weren't seeing this particular failure with the previous (non-promise) version of the test.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 23•4 years ago
|
||
Also removed debug logging, as well as about:blank check which turned out not to be the cause of the timeout.
Assignee | ||
Updated•4 years ago
|
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 25•4 years ago
|
||
Note that I'm hoping the patch in comment 23 will finally fix this.
Comment hidden (Intermittent Failures Robot) |
Comment 27•4 years ago
|
||
Changing the stockwell tag based on the above.
Comment hidden (Intermittent Failures Robot) |
Updated•4 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 32•4 years ago
|
||
Updated•4 years ago
|
Updated•4 years ago
|
Updated•4 years ago
|
Comment 33•4 years ago
|
||
Please take a look at this potential fix: https://phabricator.services.mozilla.com/D82137 before landing the disable patch.
Comment 34•4 years ago
|
||
Pushed by yura.zenevich@gmail.com: https://hg.mozilla.org/integration/autoland/rev/3e441eedb657 test_doc_busy.html: Handle the case where the busy change and not-busy change events are coalesced out of existence. r=yzen
Comment 35•4 years ago
|
||
Removing the [stockwell disable-recommended] since the fix landed. We'll monitor the failure rate for the next few days.
Comment 36•4 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Updated•4 years ago
|
Updated•4 years ago
|
Description
•