Intermittent browser/components/sessionstore/test/browser_dying_cache.js | the window has one closed tab - Got 0, expected 1

RESOLVED FIXED

Status

()

defect
RESOLVED FIXED
2 years ago
a month ago

People

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

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [stockwell disabled])

Attachments

(1 attachment)

Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
this test has a moderate failure rate, possibly it changed a few days ago, but nothing serious enough to spend much time investigating.
Whiteboard: [stockwell unknown]
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
this test picked up on April 29th for win7 opt browser-chrome-e10s.

here is a failure log:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=97949932&lineNumber=2819

and a screenshot (just the book of mozilla single tab) and it looks like there are multiple firefox windows (which browser chrome always has a controller window):
https://public-artifacts.taskcluster.net/OnTjJnaUQyWMZKIA2WsXog/0/public/test_info/mozilla-test-fail-screenshot_ldxo8v.png

and here is an example of the failure:
08:01:19     INFO -  513 INFO TEST-START | browser/components/sessionstore/test/browser_dying_cache.js
08:01:19     INFO -  TEST-INFO | started process screenshot
08:01:19     INFO -  TEST-INFO | screenshot: exit 0
08:01:19     INFO -  Buffered messages logged at 08:01:19
08:01:19     INFO -  514 INFO Entering test bound test
08:01:19     INFO -  515 INFO TEST-PASS | browser/components/sessionstore/test/browser_dying_cache.js | window is being tracked by sessionstore -
08:01:19     INFO -  516 INFO TEST-PASS | browser/components/sessionstore/test/browser_dying_cache.js | the window has a single tab -
08:01:19     INFO -  517 INFO TEST-PASS | browser/components/sessionstore/test/browser_dying_cache.js | the tab is about:mozilla -
08:01:19     INFO -  Buffered messages finished
08:01:19    ERROR -  518 INFO TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | the window has one closed tab - Got 0, expected 1
08:01:19     INFO -  Stack trace:
08:01:19     INFO -      chrome://mochikit/content/browser-test.js:test_is:928
08:01:19     INFO -      chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:checkWindowState:50
08:01:19     INFO -      chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:test:28
08:01:19     INFO -      Tester_execTest@chrome://mochikit/content/browser-test.js:752:9
08:01:19     INFO -      Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:672:7
08:01:19     INFO -      SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
08:01:19     INFO -  GECKO(5264) | *************************
08:01:19     INFO -  GECKO(5264) | A coding exception was thrown and uncaught in a Task.
08:01:19     INFO -  GECKO(5264) | Full message: TypeError: can't convert undefined to object
08:01:19     INFO -  GECKO(5264) | Full stack: checkWindowState@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:51:7
08:01:19     INFO -  GECKO(5264) | test@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:28:3
08:01:19     INFO -  GECKO(5264) | Tester_execTest@chrome://mochikit/content/browser-test.js:752:9
08:01:19     INFO -  GECKO(5264) | Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:672:7
08:01:19     INFO -  GECKO(5264) | SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
08:01:19     INFO -  GECKO(5264) | *************************
08:01:19     INFO -  Not taking screenshot here: see the one that was previously logged
08:01:19    ERROR -  519 INFO TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | Uncaught exception - at chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:51 - TypeError: can't convert undefined to object
08:01:19     INFO -  Stack trace:
08:01:19     INFO -      checkWindowState@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:51:7
08:01:19     INFO -      test@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:28:3
08:01:19 
    INFO -      Tester_execTest@chrome://mochikit/content/browser-test.js:752:9
08:01:19     INFO -      Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:672:7
08:01:19     INFO -      SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
08:01:19     INFO -      Tester_execTest@chrome://mochikit/content/browser-test.js:752:9
08:01:19     INFO -      Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:672:7
08:01:19     INFO -      SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
08:01:19     INFO -  520 INFO Leaving test bound test
08:01:19     INFO -  GECKO(5264) | MEMORY STAT | vsize 867MB | vsizeMaxContiguous 493MB | residentFast 388MB | heapAllocated 193MB
08:01:19     INFO -  521 INFO TEST-OK | browser/components/sessionstore/test/browser_dying_cache.js | took 488ms
08:01:19     INFO -  522 INFO checking window state
08:01:19     INFO -  Not taking screenshot here: see the one that was previously logged
08:01:19    ERROR -  523 INFO TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | Found an unexpected browser window at the end of test run -
08:01:19     INFO -  GECKO(5264) | must wait for focus


:mikedeboer, can you take a look at this or help find someone on the sessionrestore team to look at this failure?
Flags: needinfo?(mdeboer)
Whiteboard: [stockwell unknown] → [stockwell needswork]
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
I'm really cramped for time at the moment, so I'm hoping Will has a bit of time...?
Flags: needinfo?(mdeboer) → needinfo?(wiwang)
I will try to investigate as much as I can and I probably don't have much time for this, since I'm currently busy with some other Quantum Flow bugs..  :'(

Hi Yoric, Tim, it seems that you understood this test before, would it be possible for you to share some thoughts/clues about the first glance at the failure? 

Besides, from the orange factor history[1], I found that _almost_ all of the failures recently(from April to now) are on the windows platform, especially the 'windows7-32-vm'... I'm not sure the reason, it's likely the 'windows7-32-vm' is way too slow.


[1] https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1331853&entireHistory=true&tree=all
Flags: needinfo?(wiwang)
Flags: needinfo?(ttaubert)
Flags: needinfo?(dteller)
Sorry, I currently have no time to investigate :(
Flags: needinfo?(ttaubert)
Tim, thanks anyway! :)

==

Keep NI myself for tracking.
Flags: needinfo?(wiwang)
I don't remember anything about that test, I'm afraid. Sorry about that :/
Flags: needinfo?(dteller)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Assignee

Comment 24

2 years ago
:WillWang - Thanks for your efforts here! Since it looks like it may take some time to find a solution here, let's disable the test on Windows for now.
Attachment #8871796 - Flags: review?(wiwang)
Comment hidden (Intermittent Failures Robot)
Comment on attachment 8871796 [details] [diff] [review]
skip test on windows

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

Thanks for your work, Geoff!

== Some note for the investigation afterwards == 

From several similar logs, the test failed at:
    ERROR -  418 INFO TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | the window has one closed tab - Got 0, expected 1
which is from the code here:
    is(ss.getClosedTabCount(window), 1, "the window has one closed tab"); ......[1]
which is about after we call promiseRemoveTab(win.gBrowser.tabs[0]); ......[2]

I suspect that the test needs more time for the gap between [1] and [2], to get the correct closed tab count(we expect 1).

Set as r+ since this might not introduce too much risk, from my limited experience; and other platforms are still running this test.


[1] is(ss.getClosedTabCount(window), 1, "the window has one closed tab");
http://searchfox.org/mozilla-central/rev/1a0d9545b9805f50a70de703a3c04fc0d22e3839/browser/components/sessionstore/test/browser_dying_cache.js#50

[2] await promiseRemoveTab(win.gBrowser.tabs[0]);
http://searchfox.org/mozilla-central/rev/1a0d9545b9805f50a70de703a3c04fc0d22e3839/browser/components/sessionstore/test/browser_dying_cache.js#22
Attachment #8871796 - Flags: review?(wiwang) → review+

Comment 27

2 years ago
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/299efa8c78ee
Skip browser_dying_cache.js on Windows, for intermittent failures; r=WillWang
Assignee

Updated

2 years ago
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled]
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
In the last 7 days we have 67 failures, they started to increase with 10th of Jan.
They occur on Linux, Linux x64-disabled, linux32-nightly, disabled, OS X 10.10.
The affected build types are asan, debug, opt, pgo.
Recent log: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=155793512&lineNumber=3962
and a relevant part of it:

[task 2018-01-12T01:08:33.505Z] 01:08:33     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | the window has one closed tab - Got 0, expected 1
3963
[task 2018-01-12T01:08:33.505Z] 01:08:33     INFO - Stack trace:
3964
[task 2018-01-12T01:08:33.506Z] 01:08:33     INFO - chrome://mochikit/content/browser-test.js:test_is:1269
3965
[task 2018-01-12T01:08:33.506Z] 01:08:33     INFO - chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:checkWindowState:50
3966
[task 2018-01-12T01:08:33.507Z] 01:08:33     INFO - chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:test:28
3967
[task 2018-01-12T01:08:33.508Z] 01:08:33     INFO - Not taking screenshot here: see the one that was previously logged
3968
[task 2018-01-12T01:08:33.512Z] 01:08:33     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | Uncaught exception - at chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:51 - TypeError: JSON.parse(...)[Symbol.iterator](...).next(...).value is undefined
3969
[task 2018-01-12T01:08:33.512Z] 01:08:33     INFO - Stack trace:
3970
[task 2018-01-12T01:08:33.513Z] 01:08:33     INFO -     checkWindowState@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:51:7
3971
[task 2018-01-12T01:08:33.514Z] 01:08:33     INFO -     test@chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_dying_cache.js:28:3
3972
[task 2018-01-12T01:08:33.515Z] 01:08:33     INFO -     Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1065:21
3973
[task 2018-01-12T01:08:33.515Z] 01:08:33     INFO -     Tester_execTest@chrome://mochikit/content/browser-test.js:1056:9
3974
[task 2018-01-12T01:08:33.516Z] 01:08:33     INFO -     Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:956:9
3975
[task 2018-01-12T01:08:33.518Z] 01:08:33     INFO -     SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
3976
[task 2018-01-12T01:08:33.519Z] 01:08:33     INFO - Leaving test bound test
3977
[task 2018-01-12T01:08:33.521Z] 01:08:33     INFO - GECKO(2812) | MEMORY STAT | vsize 2767MB | residentFast 419MB | heapAllocated 163MB
3978
[task 2018-01-12T01:08:33.522Z] 01:08:33     INFO - TEST-OK | browser/components/sessionstore/test/browser_dying_cache.js | took 588ms
3979
[task 2018-01-12T01:08:33.523Z] 01:08:33     INFO - checking window state
3980
[task 2018-01-12T01:08:33.523Z] 01:08:33     INFO - Not taking screenshot here: see the one that was previously logged
3981
[task 2018-01-12T01:08:33.524Z] 01:08:33     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_dying_cache.js | Found an unexpected browser window at the end of test run - 
3982
[task 2018-01-12T01:08:33.525Z] 01:08:33     INFO - GECKO(2812) | must wait for focus
:mikedeboer, can you please take a look at this?
No longer blocks: 1373708
Flags: needinfo?(mdeboer)
Whiteboard: [stockwell disabled] → [stockwell needswork]
The frequency uptick got fixed by the backout of bug 1373708.
Blocks: 1373708
Flags: needinfo?(mdeboer)
Whiteboard: [stockwell needswork] → [stockwell disabled]
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
No longer blocks: 1373708
The leave-open keyword is there and there is no activity for 6 months.
:mikedeboer, maybe it's time to close this bug?
Flags: needinfo?(mdeboer)
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Last Resolved: a month ago
Flags: needinfo?(mdeboer)
Keywords: leave-open
Resolution: --- → FIXED
Flags: needinfo?(wiwang)

This test remains skipped on Windows. Do we plan to investigate fixing and re-enabling it there?

Flags: needinfo?(mdeboer)

No, I don't have any cycles to investigate this further than Will has tried.

Flags: needinfo?(mdeboer)
You need to log in before you can comment on or make changes to this bug.