Closed Bug 1509787 Opened 6 years ago Closed 5 years ago

Intermittent dom/tests/browser/browser_test_new_window_from_content.js | Test timed out - | Found a tab after previous test timed out: | Found a browser window after previous test timed out -

Categories

(Core :: DOM: Core & HTML, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=213786444&repo=autoland

https://queue.taskcluster.net/v1/task/b0IyqpI9QYWca6efLcXeoQ/runs/0/artifacts/public/logs/live_backing.log

07:43:11     INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54
07:43:11     INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:16:41
07:43:11     INFO - notify@resource://gre/modules/Timer.jsm:42:7
07:43:11     INFO - 
07:43:11     INFO - Buffered messages logged at 07:40:10
07:43:11     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 2
07:43:11     INFO - Buffered messages logged at 07:41:40
07:43:11     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 1
07:43:11     INFO - Buffered messages finished
07:43:11     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Test timed out - 
07:43:11     INFO - GECKO(856) | MEMORY STAT | vsize 2135MB | vsizeMaxContiguous 132353127MB | residentFast 353MB | heapAllocated 79MB
07:43:11     INFO - TEST-OK | dom/tests/browser/browser_test_new_window_from_content.js | took 270142ms
07:43:11     INFO - Not taking screenshot here: see the one that was previously logged
07:43:11     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Found a tab after previous test timed out: http://www.example.com/browser/dom/tests/browser/test_new_window_from_content_child.html - 
07:43:11     INFO - GECKO(856) | ++DOCSHELL 000001AE16A3D800 == 1 [pid = 7400] [id = {ec9312a7-912f-4b26-80fe-f2acd2d344aa}]
07:43:11     INFO - GECKO(856) | ++DOMWINDOW == 1 (000001AE16A9A400) [pid = 7400] [serial = 450] [outer = 0000000000000000]
07:43:11     INFO - GECKO(856) | ++DOMWINDOW == 2 (000001AE1C29F800) [pid = 7400] [serial = 451] [outer = 000001AE16A9A400]
07:43:11     INFO - GECKO(856) | [Child 7400, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/xpcom/io/NonBlockingAsyncInputStream.cpp, line 182
07:43:11     INFO - GECKO(856) | [Child 7400, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/xpcom/io/NonBlockingAsyncInputStream.cpp, line 182
07:43:11     INFO - GECKO(856) | [Child 7400, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/xpcom/io/NonBlockingAsyncInputStream.cpp, line 182
07:43:11     INFO - checking window state
07:43:11     INFO - GECKO(856) | ++DOMWINDOW == 3 (000001AE1CFBA000) [pid = 7400] [serial = 452] [outer = 000001AE16A9A400]
07:43:11     INFO - Not taking screenshot here: see the one that was previously logged
07:43:11     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Found a browser window after previous test timed out - 
07:43:11     INFO - GECKO(856) | [Child 7400, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/xpcom/io/NonBlockingAsyncInputStream.cpp, line 182
I don't see how it could. My patch only touched adb, which should only affect android platforms.
Flags: needinfo?(wkocher)
The test run from comment 0 has this screenshot linked as one of the artifacts at the top:
https://queue.taskcluster.net/v1/task/b0IyqpI9QYWca6efLcXeoQ/runs/0/artifacts/public/test_info/mozilla-test-fail-screenshot_xithhf.png

That seems to show that Windows has popped up a modal dialog ("Important updates are pending"), probably stealing focus and breaking the test as a result.

Here's another log with the same failure, and its screenshot which shows the same dialog:
https://treeherder.mozilla.org/logviewer.html#?job_id=214286968&repo=autoland
https://queue.taskcluster.net/v1/task/ZothYEujTy--L_TA3c0KUA/runs/0/artifacts/public/test_info/mozilla-test-fail-screenshot_wczw1y.png

So I think that windows dialog is at fault.  This probably started happening just recently because:
 (a) Microsoft just recently published some important windows updates
 (b) ...or: maybe this has always been happening, but it's less problematic if it pops up during a test that cares less about having focus.
(didn't finish my thought for (b) -- was gonna say "...and perhaps some recent test rebucketing bumped this test to be visited at just the right time during our test-run-lifetime that it's possible it intersects with this dialog".)

(no idea if this is actually the case; just throwing out possible explanations.)
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE

This is still happening.

Recent failure:

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=227748577&repo=mozilla-release&lineNumber=26379

21:53:33 INFO - Console message: [JavaScript Error: "Unknown collection "main/tippytop"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 261}]
21:53:33 INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:261:13
21:53:33 INFO -
21:53:33 INFO - Buffered messages logged at 21:50:33
21:53:33 INFO - Longer timeout required, waiting longer... Remaining timeouts: 2
21:53:33 INFO - Buffered messages logged at 21:52:03
21:53:33 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
21:53:33 INFO - Buffered messages finished
21:53:33 INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Test timed out -
21:53:33 INFO - GECKO(11164) | MEMORY STAT | vsize 6351MB | vsizeMaxContiguous 130157027MB | residentFast 433MB | heapAllocated 75MB
21:53:33 INFO - TEST-OK | dom/tests/browser/browser_test_new_window_from_content.js | took 270102ms
21:53:33 INFO - Not taking screenshot here: see the one that was previously logged
21:53:33 INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Found a tab after previous test timed out: http://www.example.com/browser/dom/tests/browser/test_new_window_from_content_child.html -
21:53:33 INFO - GECKO(11164) | ++DOCSHELL 000002674693C000 == 1 [pid = 9200] [id = {91edde21-813a-405b-b4fd-b142237995e6}]
21:53:33 INFO - GECKO(11164) | ++DOMWINDOW == 1 (00000267469B0000) [pid = 9200] [serial = 420] [outer = 0000000000000000]
21:53:33 INFO - GECKO(11164) | ++DOMWINDOW == 2 (00000267469C6000) [pid = 9200] [serial = 421] [outer = 00000267469B0000]
21:53:33 INFO - checking window state
21:53:33 INFO - Not taking screenshot here: see the one that was previously logged
21:53:33 INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_test_new_window_from_content.js | Found a browser window after previous test timed out -
21:53:33 INFO - TEST-START | dom/tests/browser/browser_test_performance_metrics_off.js
21:53:33 INFO - GECKO(11164) | Chrome file doesn't exist: Z:\task_1549920285\build\tests\mochitest\browser\dom\tests\browser\head.js
21:53:33 INFO - GECKO(11164) | MEMORY STAT | vsize 6348MB | vsizeMaxContiguous 130157027MB | residentFast 434MB | heapAllocated 75MB
21:53:33 INFO - TEST-OK | dom/tests/browser/browser_test_performance_metrics_off.js | took 72ms

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Component: DOM → DOM: Core & HTML
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.