Closed Bug 1377641 Opened 7 years ago Closed 5 years ago

Intermittent browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | Tab in closed window has the expected url. - Expected: http://example.com/, Actual: about:mozilla -

Categories

(WebExtensions :: Untriaged, defect, P5)

Product:
WebExtensions
Component:
Untriaged
Type:
defect

Tracking

(firefox66 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla66
Iteration:
65.1 - Nov 2
Tracking Flags:
Tracking Status
firefox66 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])

Attachments

(2 files)

Disable on Linux debug
926 bytes, patch
jmaher
: review+
Details | Diff | Splinter Review
Bug 1377641 - Re-enable browser_ext_sessions_getRecentlyClosed.js
47 bytes, text/x-phabricator-request
Details | Review
Priority: -- → P5
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 7 years ago → 6 years ago
Resolution: --- → INCOMPLETE
https://treeherder.mozilla.org/#/jobs?repo=autoland&fromchange=583dac82f2b5c76394515da66173cb76f285bf66&selectedJob=161190456&filter-searchStr=79d87fbd1fcd2f263d1ad926abd71464dfa6d2b5

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=161190456&repo=autoland&lineNumber=3259

14:45:56     INFO - Buffered messages finished
14:45:56     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | Tab in closed window has the expected url. - Expected: http://example.com/, Actual: about:mozilla - 
14:45:56     INFO - Stack trace:
14:45:56     INFO -     @moz-extension://a239737a-be06-de4a-966f-73d532e329eb/%7B12dff381-75f0-6544-a358-153fa4372c99%7D.js:4:7
14:45:56     INFO -     promise callback*background@moz-extension://a239737a-be06-de4a-966f-73d532e329eb/%7B12dff381-75f0-6544-a358-153fa4372c99%7D.js:2:5
14:45:56     INFO -     @moz-extension://a239737a-be06-de4a-966f-73d532e329eb/%7B12dff381-75f0-6544-a358-153fa4372c99%7D.js:1:11
14:45:56     INFO -     
14:45:56     INFO - Not taking screenshot here: see the one that was previously logged
14:45:56     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | Tab in closed window has the expected title. - 
14:45:56     INFO - Stack trace:
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Product: Toolkit → WebExtensions
There is a total of 31 failures in the last 7 days on linux32 debug, linux64 debug, osx-10-10 debug.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=194697455&repo=mozilla-inbound&lineNumber=28821

[task 2018-08-18T16:11:57.572Z] 16:11:57     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | closed tab has the expected value for windowId - 
[task 2018-08-18T16:11:57.573Z] 16:11:57     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | closed tab has the expected value for incognito - 
[task 2018-08-18T16:11:57.574Z] 16:11:57     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | each item has a unique sessionId - 
[task 2018-08-18T16:11:57.575Z] 16:11:57     INFO - Leaving test bound test_sessions_get_recently_closed
[task 2018-08-18T16:11:57.577Z] 16:11:57     INFO - Entering test bound test_sessions_get_recently_closed_navigated
[task 2018-08-18T16:11:57.578Z] 16:11:57     INFO - Extension loaded
[task 2018-08-18T16:11:57.579Z] 16:11:57     INFO - Console message: Warning: attempting to write 19613 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2018-08-18T16:11:57.588Z] 16:11:57     INFO - Buffered messages finished
[task 2018-08-18T16:11:57.590Z] 16:11:57     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | Tab in closed window has the expected url. - Expected: http://example.com/, Actual: about:mozilla - 
[task 2018-08-18T16:11:57.592Z] 16:11:57     INFO - Stack trace:
[task 2018-08-18T16:11:57.594Z] 16:11:57     INFO -     @moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:4:7
[task 2018-08-18T16:11:57.595Z] 16:11:57     INFO -     Async*background@moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:2:5
[task 2018-08-18T16:11:57.596Z] 16:11:57     INFO -     @moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:1:11
[task 2018-08-18T16:11:57.598Z] 16:11:57     INFO -     
[task 2018-08-18T16:11:57.599Z] 16:11:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-08-18T16:11:57.604Z] 16:11:57     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | Tab in closed window has the expected title. - 
[task 2018-08-18T16:11:57.605Z] 16:11:57     INFO - Stack trace:
[task 2018-08-18T16:11:57.605Z] 16:11:57     INFO -     @moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:7:7
[task 2018-08-18T16:11:57.606Z] 16:11:57     INFO -     Async*background@moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:2:5
[task 2018-08-18T16:11:57.607Z] 16:11:57     INFO -     @moz-extension://715682f7-0c24-4982-b7e3-f0df662b1a32/%7B6524c3a5-cdc9-4c38-be5b-3b7deae392a7%7D.js:1:11
[task 2018-08-18T16:11:57.607Z] 16:11:57     INFO -     
[task 2018-08-18T16:11:57.608Z] 16:11:57     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | getRecentlyClosed with navigation - 
[task 2018-08-18T16:11:57.610Z] 16:11:57     INFO - Leaving test bound test_sessions_get_recently_closed_navigated
[task 2018-08-18T16:11:57.613Z] 16:11:57     INFO - GECKO(1063) | MEMORY STAT | vsize 937MB | residentFast 478MB | heapAllocated 172MB
[task 2018-08-18T16:11:57.614Z] 16:11:57     INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js | took 16063ms
[task 2018-08-18T16:11:57.615Z] 16:11:57     INFO - GECKO(1063) | ++DOCSHELL 0xe7059000 == 6 [pid = 1210] [id = {76dc6d15-af70-47e4-823d-e4ff06f81b82}]
[task 2018-08-18T16:11:57.616Z] 16:11:57     INFO - GECKO(1063) | ++DOMWINDOW == 22 (0xe700b940) [pid = 1210] [serial = 283] [outer = (nil)]
[task 2018-08-18T16:11:57.617Z] 16:11:57     INFO - GECKO(1063) | ++DOMWINDOW == 23 (0xe705d800) [pid = 1210] [serial = 284] [outer = 0xe700b940]
[task 2018-08-18T16:11:57.618Z] 16:11:57     INFO - GECKO(1063) | ++DOMWINDOW == 24 (0xe7f65c00) [pid = 1210] [serial = 285] [outer = 0xe700b940]
[task 2018-08-18T16:11:57.620Z] 16:11:57     INFO - checking window state
[task 2018-08-18T16:11:57.640Z] 16:11:57     INFO - GECKO(1063) | --DOCSHELL 0xe7f69c00 == 5 [pid = 1210] [id = {3ab84055-fd95-47a4-a011-5b182655b53b}]
[task 2018-08-18T16:11:57.641Z] 16:11:57     INFO - GECKO(1063) | --DOCSHELL 0xe7055400 == 4 [pid = 1210] [id = {6c94e392-4d4b-4552-8c56-bc82ff22623c}]
[task 2018-08-18T16:11:57.642Z] 16:11:57     INFO - GECKO(1063) | --DOCSHELL 0xe7f68c00 == 3 [pid = 1210] [id = {d13313d5-70f0-4ab2-b223-b5d44646a27e}]
[task 2018-08-18T16:11:57.643Z] 16:11:57     INFO - GECKO(1063) | --DOMWINDOW == 23 (0xe700b160) [pid = 1210] [serial = 256] [outer = (nil)] [url = http://example.com/]
[task 2018-08-18T16:11:57.644Z] 16:11:57     INFO - GECKO(1063) | --DOMWINDOW == 22 (0xe700b040) [pid = 1210] [serial = 260] [outer = (nil)] [url = http://example.com/]
[task 2018-08-18T16:11:57.645Z] 16:11:57     INFO - GECKO(1063) | --DOMWINDOW == 21 (0xe848f700) [pid = 1210] [serial = 267] [outer = (nil)] [url = about:newtab]

Davind, can you take a look?
Flags: needinfo?(ddurst)
Whiteboard: [stockwell needswork]
There are 44 occurrence for this failure in the last 7 days. This is mostly happening on Linux 32 & 64 debug.
The test failed at:
https://searchfox.org/mozilla-central/rev/2fe43133dbc774dda668d4597174d73e3969181a/browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js#99-103,118-127

It seems that getRecentlyClosed was called before the ultimate destination was saved to session store.

Mike, is BrowserTestUtils.browserLoaded a good way to ensure that the the tab is saved to session store? If not, what should be used instead?
Flags: needinfo?(mdeboer)
Hi mdeboer: Have you had a chance to take a look at this bug yet?
Hi! Made a patch to disable this on Linux debug. Left out OSX because there are only 4 failures in the last 7 days. Thanks.
Assignee: nobody → csabou
Attachment #9007985 - Flags: review?(jmaher)
Assignee: csabou → nobody
Attachment #9007985 - Flags: review?(jmaher) → review+
Keywords: checkin-needed, leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2712c242569c
Disable browser/components/extensions/test/browser/browser_ext_sessions_getRecentlyClosed.js on Linux debug for frequent failures. r=jmaher
Keywords: checkin-needed
(In reply to Rob Wu [:robwu] from comment #26)
> The test failed at:
> https://searchfox.org/mozilla-central/rev/
> 2fe43133dbc774dda668d4597174d73e3969181a/browser/components/extensions/test/
> browser/browser_ext_sessions_getRecentlyClosed.js#99-103,118-127
> 
> It seems that getRecentlyClosed was called before the ultimate destination
> was saved to session store.
> 
> Mike, is BrowserTestUtils.browserLoaded a good way to ensure that the the
> tab is saved to session store? If not, what should be used instead?

Hi Rob - sorry for the late reply! Ugh.

So to ensure a tab is saved to Sessionstore, please use `await TabStateFlusher.flush(browser);`, which is available to you when you import TabStateFlusher.jsm. I hope that helps! Please feel free to ping me on IRC/ Slack for any question(s) you might have.
Flags: needinfo?(mdeboer)
Thanks for that answer. I'll give it a try.
Assignee: nobody → rob
Status: REOPENED → ASSIGNED
Flags: needinfo?(ddurst)
I've been investigating this - using TabStateFlusher.flush does not fix the intermittent on Linux debug:
https://bugzilla.mozilla.org/show_bug.cgi?id=1488524

(and neither does "sessionstore-closed-objects-changed").

I'll look into this again in a few weeks.
Iteration: --- → 65.1 (Nov 2)
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/824302f53841
Re-enable browser_ext_sessions_getRecentlyClosed.js r=mixedpuppy
Status: ASSIGNED → RESOLVED
Closed: 6 years ago → 5 years ago
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [stockwell disabled] → [stockwell fixed]
status-firefox66: --- → fixed
Target Milestone: --- → mozilla66

Is any QA validation required on this bug?

Flags: needinfo?(rob)
Flags: needinfo?(rob) → qe-verify-
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: