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

RESOLVED FIXED in Firefox 39

Status

()

Firefox
Session Restore
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: RyanVM, Assigned: mossop)

Tracking

({intermittent-failure})

unspecified
Firefox 39
x86
Linux
intermittent-failure
Points:
1
Bug Flags:
firefox-backlog +
qe-verify -

Firefox Tracking Flags

(firefox37 unaffected, firefox38 unaffected, firefox39 fixed, firefox-esr31 unaffected)

Details

Attachments

(2 attachments, 1 obsolete attachment)

(Reporter)

Description

3 years ago
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)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 4

3 years ago
Created attachment 8577403 [details] [diff] [review]
patch

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 hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
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 :)
(Assignee)

Comment 10

3 years ago
Created attachment 8577443 [details] [diff] [review]
patch
Attachment #8577403 - Attachment is obsolete: true
Attachment #8577443 - Flags: review?(ttaubert)
Attachment #8577443 - Flags: review?(ttaubert) → review+
(Assignee)

Comment 11

3 years ago
https://hg.mozilla.org/integration/fx-team/rev/df9885962214
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/mozilla-central/rev/df9885962214
Status: NEW → RESOLVED
Last Resolved: 3 years ago
status-firefox39: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 39
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
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+
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Updated

3 years ago
status-firefox37: --- → unaffected
status-firefox38: --- → unaffected
status-firefox-esr31: --- → unaffected
Comment hidden (Treeherder Robot)
(Assignee)

Updated

3 years ago
Points: --- → 1
Flags: qe-verify?
Flags: qe-verify-
Flags: needinfo?(dtownsend)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 31

3 years ago
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.
Comment hidden (Treeherder Robot)
(Assignee)

Comment 34

3 years ago
Created attachment 8578143 [details] [diff] [review]
another patch

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+
(Assignee)

Comment 35

3 years ago
https://hg.mozilla.org/integration/fx-team/rev/75dc344c04d1
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/mozilla-central/rev/75dc344c04d1
Status: REOPENED → RESOLVED
Last Resolved: 3 years ago3 years ago
Resolution: --- → FIXED
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
You need to log in before you can comment on or make changes to this bug.