Bug 1231422 - Intermittent browser_async_window_flushing.js | We should not have added the window to the closed windows array

Bug 1231422 - Intermittent browser_async_window_flushing.js | We should not have added the window to the closed windows array - Got 1, expected 0

https://treeherder.mozilla.org/#/jobs?repo=try&revision=2befbfc27b7f

07:09:52 INFO - mconley: THE INTERESTING STUFF IS STARTING
07:09:52 INFO - ++DOCSHELL 0x7ff05b71d000 == 66 [pid = 2056] [id = 625]
07:09:52 INFO - ++DOMWINDOW == 155 (0x7ff056e73800) [pid = 2056] [serial = 1896] [outer = (nil)]
07:09:52 INFO - ++DOMWINDOW == 156 (0x7ff056e77c00) [pid = 2056] [serial = 1897] [outer = 0x7ff056e73800]
07:09:52 INFO - ++DOCSHELL 0x7ff05b73b000 == 67 [pid = 2056] [id = 626]
07:09:52 INFO - ++DOMWINDOW == 157 (0x7ff0576cc800) [pid = 2056] [serial = 1898] [outer = (nil)]
07:09:52 INFO - ++DOCSHELL 0x7ff05b73b800 == 68 [pid = 2056] [id = 627]
07:09:52 INFO - ++DOMWINDOW == 158 (0x7ff0576cd000) [pid = 2056] [serial = 1899] [outer = (nil)]
07:09:52 INFO - ++DOMWINDOW == 159 (0x7ff0576cf400) [pid = 2056] [serial = 1900] [outer = 0x7ff0576cd000]
07:09:53 INFO - ++DOCSHELL 0x7ff05bb63800 == 69 [pid = 2056] [id = 628]
07:09:53 INFO - ++DOMWINDOW == 160 (0x7ff0576cc400) [pid = 2056] [serial = 1901] [outer = (nil)]
07:09:53 INFO - ++DOMWINDOW == 161 (0x7ff057edbc00) [pid = 2056] [serial = 1902] [outer = 0x7ff0576cc400]
07:09:53 INFO - ++DOMWINDOW == 162 (0x7ff0580afc00) [pid = 2056] [serial = 1903] [outer = 0x7ff0576cc800]
07:09:53 INFO - ++DOMWINDOW == 163 (0x7ff058154800) [pid = 2056] [serial = 1904] [outer = 0x7ff0576cd000]
07:09:53 INFO - ++DOMWINDOW == 164 (0x7ff058159c00) [pid = 2056] [serial = 1905] [outer = 0x7ff0576cc400]
07:09:54 INFO - ++DOMWINDOW == 165 (0x7ff058bcb000) [pid = 2056] [serial = 1906] [outer = 0x7ff0576cc400]
07:09:54 INFO - mconley: CLOSING THE WINDOW
07:09:54 INFO - mconley: A window closed
07:09:54 INFO - mconley: Determining if {
07:09:54 INFO - "tabs": [
07:09:54 INFO - {
07:09:54 INFO - "entries": [
07:09:54 INFO - {
07:09:54 INFO - "url": " http://example.com/ ",
07:09:54 INFO - "charset": "UTF-8",
07:09:54 INFO - "ID": 734,
07:09:54 INFO - "docshellID": 628,
07:09:54 INFO - "docIdentifier": 734,
07:09:54 INFO - "persist": true
07:09:54 INFO - }
07:09:54 INFO - ],
07:09:54 INFO - "lastAccessed": 1453475394888,
07:09:54 INFO - "hidden": false,
07:09:54 INFO - "attributes": {},
07:09:54 INFO - "userContextId": 0,
07:09:54 INFO - "index": 1,
07:09:54 INFO - "image": null
07:09:54 INFO - }
07:09:54 INFO - ],
07:09:54 INFO - "selected": 1,
07:09:54 INFO - "_closedTabs": [],
07:09:54 INFO - "width": 1280,
07:09:54 INFO - "height": 1040,
07:09:54 INFO - "screenX": 66,
07:09:54 INFO - "screenY": 52,
07:09:54 INFO - "sizemode": "normal",
07:09:54 INFO - "title": " http://example.com/ ",
07:09:54 INFO - "_shouldRestore": true,
07:09:54 INFO - "closedAt": 1453475394901
07:09:54 INFO - } is worth saving.
07:09:54 INFO - mconley: Testing if we should save tab state: {
07:09:54 INFO - "entries": [
07:09:54 INFO - {
07:09:54 INFO - "url": " http://example.com/ ",
07:09:54 INFO - "charset": "UTF-8",
07:09:54 INFO - "ID": 734,
07:09:54 INFO - "docshellID": 628,
07:09:54 INFO - "docIdentifier": 734,
07:09:54 INFO - "persist": true
07:09:54 INFO - }
07:09:54 INFO - ],
07:09:54 INFO - "lastAccessed": 1453475394888,
07:09:54 INFO - "hidden": false,
07:09:54 INFO - "attributes": {},
07:09:54 INFO - "userContextId": 0,
07:09:54 INFO - "index": 1,
07:09:54 INFO - "image": null
07:09:54 INFO - }
07:09:54 INFO - mconley: hasSaveableTabs: true - isLastWindow: false
07:09:54 INFO - mconley: Inserting tabData
07:09:55 INFO - mconley: DOMWindowClosed has fired - now checking the current closed window count
07:09:55 INFO - The count is: 1
07:09:55 INFO - TEST-INFO | started process screentopng
07:09:56 INFO - TEST-INFO | screentopng: exit 0
07:09:56 INFO - 195 INFO checking window state
07:09:56 INFO - 196 INFO Console message: [JavaScript Error: "TelemetryStopwatch: requesting elapsed time for nonexisting stopwatch. Histogram: "FX_PAGE_LOAD_MS", key: "null"" {file: "resource://gre/modules/TelemetryStopwatch.jsm" line: 297}]
07:09:56 INFO - 197 INFO Entering test test_add_interesting_window
07:09:56 INFO - 198 INFO TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_async_window_flushing.js | We should not have added the window to the closed windows array - Got 1, expected 0
07:09:56 INFO - Stack trace:
07:09:56 INFO - chrome://mochikit/content/browser-test.js:test_is:979
07:09:56 INFO - chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_async_window_flushing.js:test_add_interesting_window:74
07:09:56 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:803:9
07:09:56 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:723:7

07:09:56 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:735:59

Oh noooooooooooo. I know what’s happening.

My observer for the browser.sessionstore.debug.no_auto_updates pref isn’t working because the observer function is comparing the _topic_ against browser.sessionstore.debug.no_auto_updates and not the data! WOE IS ME.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=36b3f28cd14b

Huh. And this landed, and the bug remains. WTactualF?

MOAR LOGGING: https://treeherder.mozilla.org/#/jobs?repo=try&revision=e3b88268ddf8

Aw cripes, this is another embarrassing thing - when timeoutDisabled is set to true, active timers aren’t canceled. 😔

Try build: https://treeherder.mozilla.org/#/jobs?repo=try&revision=03c1b1945fdb

Could… could this be somehow related to bug 1195295?

I don’t think so. Still, patch posted.