Closed Bug 1143118 Opened 9 years ago Closed 9 years ago

Intermittent browser_tab_detach_restore.js | Uncaught exception - at resource://testing-common/BrowserTestUtils.jsm:133 - Error: SSTabRestored event timeout at waitForEvent/<@resource://testing-common/BrowserTestUtils.jsm:127:19

Categories

(Firefox :: Session Restore, defect)

x86
Linux
defect
Not set
normal
Points:
1

Tracking

()

RESOLVED FIXED
Firefox 39
Iteration:
39.2 - 23 Mar
Tracking Status
firefox37 --- unaffected
firefox38 --- unaffected
firefox39 --- fixed
firefox-esr31 --- unaffected

People

(Reporter: RyanVM, Assigned: mossop)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files, 1 obsolete file)

10:29:17 INFO - 587 INFO checking window state
10:29:17 INFO - 588 INFO Entering test
10:29:17 INFO - 589 INFO Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/browser/base/content/test/general/dummy_page.html" line: 0}]
10:29:17 INFO - 590 INFO TEST-PASS | browser/base/content/test/general/browser_tab_detach_restore.js | Should have properly copied the permanentKey
10:29:17 INFO - 591 INFO TEST-PASS | browser/base/content/test/general/browser_tab_detach_restore.js | Should have restore data for the closed window
10:29:17 INFO - 592 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_tab_detach_restore.js | Uncaught exception - at resource://testing-common/BrowserTestUtils.jsm:133 - Error: load event timeout at waitForEvent/<@resource://testing-common/BrowserTestUtils.jsm:129:19
10:29:17 INFO - waitForEvent@resource://testing-common/BrowserTestUtils.jsm:117:1
10:29:17 INFO - @chrome://mochitests/content/browser/browser/base/content/test/general/browser_tab_detach_restore.js:24:9
10:29:17 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:314:40
10:29:17 INFO - Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:867:23
10:29:17 INFO - this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:746:7
10:29:17 INFO - this.PromiseWalker.scheduleWalkerLoop/<@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:688:37
10:29:17 INFO - Stack trace:
10:29:17 INFO - waitForEvent/</timerID<@resource://testing-common/BrowserTestUtils.jsm:133:16
10:29:17 INFO - setTimeout_timer@resource://gre/modules/Timer.jsm:30:5
10:29:17 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:693:9
10:29:17 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:616:7
10:29:17 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:752:59
10:29:17 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:693:9
10:29:17 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:616:7
10:29:17 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:752:59
10:29:17 INFO - 593 INFO Leaving test
10:29:17 INFO - --DOMWINDOW == 199 (0x7f064e747700) [pid = 2164] [serial = 2189] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 198 (0x7f064e74a100) [pid = 2164] [serial = 2197] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 197 (0x7f064e748c00) [pid = 2164] [serial = 2193] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 196 (0x7f064e74c780) [pid = 2164] [serial = 2201] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 195 (0x7f0640eb5880) [pid = 2164] [serial = 2166] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 194 (0x7f064e747000) [pid = 2164] [serial = 2187] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 193 (0x7f064e749a00) [pid = 2164] [serial = 2195] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 192 (0x7f064e747e00) [pid = 2164] [serial = 2191] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 191 (0x7f064e74ab80) [pid = 2164] [serial = 2199] [outer = (nil)] [url = about:blank]
10:29:17 INFO - --DOMWINDOW == 190 (0x7f0647ce8900) [pid = 2164] [serial = 2185] [outer = (nil)] [url = about:blank]
10:29:18 INFO - 594 INFO MEMORY STAT vsize after test: 1683640320
10:29:18 INFO - 595 INFO MEMORY STAT residentFast after test: 483639296
10:29:18 INFO - 596 INFO MEMORY STAT heapAllocated after test: 185672056
10:29:18 INFO - 597 INFO TEST-OK | browser/base/content/test/general/browser_tab_detach_restore.js | took 4512ms
10:29:18 INFO - ++DOCSHELL 0x7f06457d1400 == 53 [pid = 2164] [id = 899]
10:29:18 INFO - ++DOMWINDOW == 191 (0x7f0632bed980) [pid = 2164] [serial = 2338] [outer = (nil)]
10:29:18 INFO - ++DOMWINDOW == 192 (0x7f0632bee400) [pid = 2164] [serial = 2339] [outer = 0x7f0632bed980]
10:29:18 INFO - [2164] WARNING: NS_ENSURE_TRUE(mMutable) failed: file /builds/slave/m-cen-l64-d-000000000000000000/build/src/netwerk/base/nsSimpleURI.cpp, line 265
10:29:18 INFO - 598 INFO checking window state
10:29:18 INFO - 599 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_tab_detach_restore.js | Found an unexpected browser window at the end of test run - expected PASS
Flags: needinfo?(dtownsend)
Attached patch patch (obsolete) — Splinter Review
Kind of surprised we aren't getting a load event here but waitForFocus checks if the window is loaded and if not waits for load so maybe that will help?
Flags: needinfo?(dtownsend)
Attachment #8577403 - Flags: review?(ttaubert)
Comment on attachment 8577403 [details] [diff] [review]
patch

Review of attachment 8577403 [details] [diff] [review]:
-----------------------------------------------------------------

We're hitting this on debug builds only. My guess is that waitForEvent's default timeout at two seconds is just low enough to sometimes fire before the window had a chance to load. Not a fan of event listeners with timeouts but the easy way to fix this would be to pass something like 10s maybe?
Attachment #8577403 - Flags: review?(ttaubert) → review-
Just realized that your patch would have actually fixed this. I guess it's still better to only wait for what's necessary and understand what was going on :)
Attached patch patchSplinter Review
Attachment #8577403 - Attachment is obsolete: true
Attachment #8577443 - Flags: review?(ttaubert)
Attachment #8577443 - Flags: review?(ttaubert) → review+
https://hg.mozilla.org/mozilla-central/rev/df9885962214
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 39
Hi Dave, can you provide a point value.
Assignee: nobody → dtownsend
Iteration: --- → 39.2 - 23 Mar
Flags: qe-verify?
Flags: needinfo?(dtownsend)
Flags: firefox-backlog+
Points: --- → 1
Flags: qe-verify?
Flags: qe-verify-
Flags: needinfo?(dtownsend)
Well we managed to change the error
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Summary: Intermittent browser_tab_detach_restore.js | Uncaught exception - at resource://testing-common/BrowserTestUtils.jsm:133 - Error: load event timeout at waitForEvent/<@resource://testing-common/BrowserTestUtils.jsm:129:19 → Intermittent browser_tab_detach_restore.js | Uncaught exception - at resource://testing-common/BrowserTestUtils.jsm:133 - Error: SSTabRestored event timeout at waitForEvent/<@resource://testing-common/BrowserTestUtils.jsm:127:19
Yeah... still a debug VM, still a low timeout :/ We should really think about removing the timeout, I don't really think that serves a purpose other than slightly changing the error message in case there is no event at all.
Attached patch another patchSplinter Review
Right. I don't like the timeout by default either, it means we don't get screenshots when tests time out.
Attachment #8578143 - Flags: review?(ttaubert)
Attachment #8578143 - Flags: review?(ttaubert) → review+
https://hg.mozilla.org/mozilla-central/rev/75dc344c04d1
Status: REOPENED → RESOLVED
Closed: 9 years ago9 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: