Intermittent dom/xul/test/test_bug757137.xul | Test timed out.

RESOLVED FIXED in Firefox 67

Status

()

defect
P5
normal
RESOLVED FIXED
3 years ago
5 months ago

People

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

Tracking

({bulk-close-intermittents, intermittent-failure})

unspecified
mozilla68
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox67 fixed, firefox68 fixed)

Details

(Whiteboard: [stockwell unknown])

Attachments

(1 attachment)

Android only...maybe skip on Android?

Logs end with

[task 2017-02-10T22:17:27.556194Z] 22:17:27     INFO -  Buffered messages logged at 22:12:19
[task 2017-02-10T22:17:27.556270Z] 22:17:27     INFO -  46 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | nsIDOMChromeWindow interface is defined
[task 2017-02-10T22:17:27.556322Z] 22:17:27     INFO -  47 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | XUL window should QI to ChromeWindow
[task 2017-02-10T22:17:27.564868Z] 22:17:27     INFO -  Buffered messages finished
[task 2017-02-10T22:17:27.565188Z] 22:17:27     INFO -  48 INFO TEST-UNEXPECTED-FAIL | dom/xul/test/test_bug757137.xul | Test timed out.

https://dxr.mozilla.org/mozilla-central/rev/0eef1d5a39366059677c6d7944cfe8a97265a011/dom/xul/test/test_bug757137.xul#32

Logcats end with:

02-09 18:21:16.440   794   815 I GeckoDump: ⰲ겿{"action":"test_status","time":1486693276439,"thread":null,"pid":null,"source":"mochitest","test":"chrome://mochitests/content/chrome/dom/xul/test/test_bug757137.xul","subtest":"XUL window should QI to ChromeWindow","status":"PASS","js_source":"TestRunner.js"}ⰲ겿
02-09 18:21:17.490   794   815 I nsScreenManagerAndroid: nsWindow[0x5e482bc0]::Resize [0.000000 0.000000 608.000000 308.000000] (repaint 1)
02-09 18:21:17.490   794   815 I nsScreenManagerAndroid: nsWindow: 0x5e482bc0 OnSizeChanged [608 308]
02-09 18:21:17.490   794   815 I nsScreenManagerAndroid: nsWindow[0x5e482bc0]::Show 1
02-09 18:21:17.850   794   815 D dalvikvm: GC_FOR_ALLOC freed 215K, 14% free 6363K/7392K, paused 40ms, total 44ms
02-09 18:21:17.850   794   815 I dalvikvm-heap: Grow heap (frag case) to 6.641MB for 376336-byte allocation
02-09 18:21:17.900   794   803 D dalvikvm: GC_FOR_ALLOC freed 1K, 14% free 6729K/7760K, paused 40ms, total 40ms
02-09 18:21:18.311   794   794 D GeckoToolbar: onTabChanged: THUMBNAIL
02-09 18:21:18.311   794   794 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: THUMBNAIL
02-09 18:21:18.540   794   794 D GeckoToolbar: onTabChanged: THUMBNAIL
02-09 18:21:18.550   794   794 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: THUMBNAIL
Still failing intermittently on Android, as shown in comment 10.
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Recent log failure:

https://treeherder.mozilla.org/logviewer.html#?job_id=184526949&repo=mozilla-central&lineNumber=1327 

[task 2018-06-23T22:34:54.659Z] 22:34:54     INFO -  12 INFO None13 INFO TEST-START | dom/xul/test/test_bug583948.xul
[task 2018-06-23T22:35:04.980Z] 22:35:04     INFO -  14 INFO TEST-OK | dom/xul/test/test_bug583948.xul | took 9161ms
[task 2018-06-23T22:35:04.980Z] 22:35:04     INFO -  15 INFO None16 INFO TEST-START | dom/xul/test/test_bug757137.xul
[task 2018-06-23T22:40:13.266Z] 22:40:13     INFO -  Buffered messages logged at 22:35:02
[task 2018-06-23T22:40:13.267Z] 22:40:13     INFO -  17 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | nsIDOMChromeWindow interface is defined
[task 2018-06-23T22:40:13.267Z] 22:40:13     INFO -  18 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | XUL window should QI to ChromeWindow
[task 2018-06-23T22:40:13.267Z] 22:40:13     INFO -  Buffered messages finished
[task 2018-06-23T22:40:13.267Z] 22:40:13     INFO -  19 INFO TEST-UNEXPECTED-FAIL | dom/xul/test/test_bug757137.xul | Test timed out.
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Priority: -- → P5
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 2 years agoLast year
Resolution: --- → INCOMPLETE
Recent failure log:
https://treeherder.mozilla.org/logviewer.html#?job_id=192866524&repo=mozilla-inbound&lineNumber=1661

[task 2018-08-08T21:45:06.889Z] 21:45:06     INFO -  10 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | XUL window should be a ChromeWindow
[task 2018-08-08T21:45:06.890Z] 21:45:06     INFO -  Buffered messages finished
[task 2018-08-08T21:45:06.890Z] 21:45:06     INFO -  11 INFO TEST-UNEXPECTED-FAIL | dom/xul/test/test_bug757137.xul | Test timed out.
[task 2018-08-08T21:45:06.890Z] 21:45:06     INFO -  reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:7
[task 2018-08-08T21:45:06.891Z] 21:45:06     INFO -  TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
[task 2018-08-08T21:45:06.891Z] 21:45:06     INFO -  12 INFO TEST-OK | dom/xul/test/test_bug757137.xul | took 304426ms
[task 2018-08-08T21:45:06.891Z] 21:45:06     INFO -  13 INFO TEST-START | dom/xul/test/test_bug775972.xul
[task 2018-08-08T21:45:06.892Z] 21:45:06     INFO -  14 INFO TEST-OK | dom/xul/test/test_bug775972.xul | took 1629ms
[task 2018-08-08T21:45:06.892Z] 21:45:06     INFO -  15 INFO TEST-START | dom/xul/test/test_import_xul_to_content.xul
[task 2018-08-08T21:45:17.210Z] 21:45:17     INFO -  16 INFO TEST-OK | dom/xul/test/test_import_xul_to_content.xul | took 4703ms
[task 2018-08-08T21:45:17.210Z] 21:45:17     INFO -  17 INFO TEST-START | Shutdown
[task 2018-08-08T21:45:17.210Z] 21:45:17     INFO -  18 INFO Passed:  26
[task 2018-08-08T21:45:17.210Z] 21:45:17  WARNING -  19 INFO Failed:  1
[task 2018-08-08T21:45:17.210Z] 21:45:17  WARNING -  One or more unittests failed.
[task 2018-08-08T21:45:17.210Z] 21:45:17     INFO -  20 INFO Todo:    0
[task 2018-08-08T21:45:17.210Z] 21:45:17     INFO -  21 INFO Mode:    non-e10s
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: Last year7 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There are 23 total failures in the last 7 days on android-em-4-3-armv7-api16 debug

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=231748492&repo=autoland&lineNumber=1626

[task 2019-03-04T22:48:43.983Z] 22:48:43 INFO - 82 INFO TEST-START | dom/xul/test/test_bug757137.xul
[task 2019-03-04T22:53:50.787Z] 22:53:50 INFO - Buffered messages logged at 22:48:43
[task 2019-03-04T22:53:50.787Z] 22:53:50 INFO - 83 INFO TEST-PASS | dom/xul/test/test_bug757137.xul | XUL window should be a ChromeWindow
[task 2019-03-04T22:53:50.787Z] 22:53:50 INFO - Buffered messages finished
[task 2019-03-04T22:53:50.788Z] 22:53:50 INFO - 84 INFO TEST-UNEXPECTED-FAIL | dom/xul/test/test_bug757137.xul | Test timed out.
[task 2019-03-04T22:53:50.788Z] 22:53:50 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:275:18
[task 2019-03-04T22:53:50.788Z] 22:53:50 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
[task 2019-03-04T22:53:50.789Z] 22:53:50 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
[task 2019-03-04T22:53:50.789Z] 22:53:50 INFO - 85 INFO TEST-OK | dom/xul/test/test_bug757137.xul | took 305735ms
[task 2019-03-04T22:54:01.000Z] 22:54:00 INFO - 86 INFO TEST-START | dom/xul/test/test_bug775972.xul
[task 2019-03-04T22:54:01.000Z] 22:54:01 INFO - 87 INFO TEST-OK | dom/xul/test/test_bug775972.xul | took 2410ms
[task 2019-03-04T22:54:01.001Z] 22:54:01 INFO - 88 INFO TEST-START | dom/xul/test/test_import_xul_to_content.xul
[task 2019-03-04T22:54:11.219Z] 22:54:11 INFO - 89 INFO TEST-OK | dom/xul/test/test_import_xul_to_content.xul | took 5753ms
[task 2019-03-04T22:54:11.220Z] 22:54:11 INFO - 90 INFO TEST-START | Shutdown
[task 2019-03-04T22:54:11.220Z] 22:54:11 INFO - 91 INFO Passed: 72
[task 2019-03-04T22:54:11.220Z] 22:54:11 WARNING - 92 INFO Failed: 1
[task 2019-03-04T22:54:11.221Z] 22:54:11 WARNING - One or more unittests failed.
[task 2019-03-04T22:54:11.221Z] 22:54:11 INFO - 93 INFO Todo: 0
[task 2019-03-04T22:54:11.221Z] 22:54:11 INFO - 94 INFO Mode: non-e10s
[task 2019-03-04T22:54:11.222Z] 22:54:11 INFO - 95 INFO Slowest: 305734ms - chrome://mochitests/content/chrome/dom/xul/test/test_bug757137.xul
[task 2019-03-04T22:54:11.222Z] 22:54:11 INFO - 96 INFO SimpleTest FINISHED
[task 2019-03-04T22:55:04.464Z] 22:55:04 INFO - wait for org.mozilla.fennec_aurora complete; top activity=com.android.launcher
[task 2019-03-04T22:55:04.769Z] 22:55:04 INFO - remoteautomation.py | Application ran for: 0:10:34.842220
[task 2019-03-04T22:55:05.288Z] 22:55:05 INFO - /data/tombstones does not exist; tombstone check skipped
[task 2019-03-04T22:55:05.907Z] 22:55:05 INFO - Stopping web server
[task 2019-03-04T22:55:05.914Z] 22:55:05 INFO - Stopping web socket server
[task 2019-03-04T22:55:05.935Z] 22:55:05 INFO - Stopping ssltunnel
[task 2019-03-04T22:55:05.955Z] 22:55:05 INFO - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2019-03-04T22:55:05.956Z] 22:55:05 INFO - runtests.py | Running tests: end.
[task 2019-03-04T22:55:06.687Z] 22:55:06 INFO - Buffered messages finished
[task 2019-03-04T22:55:09.518Z] 22:55:09 INFO - 0 INFO TEST-START | Shutdown
[task 2019-03-04T22:55:09.518Z] 22:55:09 INFO - 1 INFO Passed: 332
[task 2019-03-04T22:55:09.518Z] 22:55:09 WARNING - 2 INFO Failed: 1
[task 2019-03-04T22:55:09.518Z] 22:55:09 WARNING - One or more unittests failed.
[task 2019-03-04T22:55:09.518Z] 22:55:09 INFO - 3 INFO Todo: 2
[task 2019-03-04T22:55:09.518Z] 22:55:09 INFO - 4 INFO Mode: non-e10s
[task 2019-03-04T22:55:09.518Z] 22:55:09 INFO - 5 INFO SimpleTest FINISHED

Hsin-Yi can you assign someone to take a look at this?

Flags: needinfo?(htsai)
Whiteboard: [stockwell needswork:owner]
Component: DOM → DOM: Core & HTML

Hi Boris, this test was added for gaia. Should we consider to remove it? I'm not sure if this test is still valuable and helpful. Thanks.

Flags: needinfo?(htsai) → needinfo?(bzbarsky)

The test basically tests something about mozbrowser behavior. We care about it to the extent that we're using mozbrowser, which is only for devtools responsive mode.

That said, fixing this test is not hard, it looks like. The problem is that the changes made to this test in https://searchfox.org/mozilla-central/commit/45de248a8b9ce78553625f547b1c88e4a60997c8 are just bogus. Before that, the test used to set a pref that would affect loading behavior, then open a window and rely on it getting the behavior the pref set. After that change, the test starts opening a new window, then starts asynchronously setting a pref. The two things race against each other, and depending on who wins the race either we end up testing what we want to test or timing out.

The right fix, presumably is to put all the bits of the test that used to be after the pref set (so including the window.open call) inside the pref push callback.

Flags: needinfo?(bzbarsky)
Assignee: nobody → bzbarsky
Attachment #9052492 - Attachment description: Bug 1322645. Fix intermittent test timeout by making sure out prefs are set before we start doing parts of the test. r=jmaher → Bug 1322645. Fix intermittent test timeout by making sure our prefs are set before we start doing parts of the test. r=jmaher
Status: REOPENED → RESOLVED
Closed: 7 months ago5 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla68
You need to log in before you can comment on or make changes to this bug.