1509787 - 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 -

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

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

Comment 1

[Cristina Coroiu [:ccoroiu]]

Retriggered bc7 on this range:
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C10%2Cx64%2Casan%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows10-64-asan%2Fopt-mochitest-browser-chrome-e10s-7%2Cm-e10s%28bc7%29&tochange=e321cef882b8caf0063cf9d17eec89a8b3170606&group_state=expanded&fromchange=2c4f0bf2be1c6a47ca537ce552099bb9eefbe5be&selectedJob=214312559

These failures moves chunks so I continued the retriggers for bc6 up to: 
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C10%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows10-64%2Fdebug-mochitest-browser-chrome-e10s-6%2Cm-e10s%28bc6%29&tochange=6ee93495fe0c47bdad591490f9a4439cbcb09be5&fromchange=b4a6bd0a9e002eee161b2b7a804f56a821e82590&group_state=expanded&selectedJob=214295339

:kwierso could be https://bugzilla.mozilla.org/show_bug.cgi?id=1509614 the culprit? could you please take a look?

Comment 2

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

I don't see how it could. My patch only touched adb, which should only affect android platforms.

Comment 3

[Daniel Holbert [:dholbert] (vacation until Jun 23)]

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.

Comment 4

[Daniel Holbert [:dholbert] (vacation until Jun 23)]

(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.)

Comment 5

[Intermittent Failures Robot]

18 failures in 2808 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 5
* autoland: 11
* mozilla-central: 2

Platform breakdown:
* windows10-64: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509787&startday=2018-11-26&endday=2018-12-02&tree=all

Comment 6

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 7

[Bogdan Tara[:bogdan_tara | bogdant]]

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

Comment 8

[Intermittent Failures Robot]

1 failures in 2832 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509787&startday=2019-02-11&endday=2019-02-17&tree=all

Comment 9

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup