1348583 - Intermittent browser/components/sessionstore/test/browser_625016.js | observe1: 1 window in data written to disk - Got 0, expected 1

Status: NEW

(Firefox :: Session Restore, defect)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://treeherder.mozilla.org/logviewer.html#?job_id=84832397&repo=autoland

[task 2017-03-18T16:42:48.480813Z] 16:42:48     INFO - Entering test bound setup
[task 2017-03-18T16:42:48.481089Z] 16:42:48     INFO - Buffered messages logged at 16:42:30
[task 2017-03-18T16:42:48.483253Z] 16:42:48     INFO - TEST-PASS | browser/components/sessionstore/test/browser_625016.js | starting with no closed windows - 
[task 2017-03-18T16:42:48.485231Z] 16:42:48     INFO - Leaving test bound setup
[task 2017-03-18T16:42:48.487463Z] 16:42:48     INFO - Entering test bound new_window
[task 2017-03-18T16:42:48.490066Z] 16:42:48     INFO - Buffered messages logged at 16:42:44
[task 2017-03-18T16:42:48.492006Z] 16:42:48     INFO - TEST-PASS | browser/components/sessionstore/test/browser_625016.js | no closed windows on first save - 
[task 2017-03-18T16:42:48.495330Z] 16:42:48     INFO - Buffered messages finished
[task 2017-03-18T16:42:48.498123Z] 16:42:48     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_625016.js | observe1: 1 window in data written to disk - Got 0, expected 1
[task 2017-03-18T16:42:48.506314Z] 16:42:48     INFO - Stack trace:
[task 2017-03-18T16:42:48.509326Z] 16:42:48     INFO -     chrome://mochikit/content/browser-test.js:test_is:911
[task 2017-03-18T16:42:48.511241Z] 16:42:48     INFO -     chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_625016.js:new_window:38
[task 2017-03-18T16:42:48.513266Z] 16:42:48     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T16:42:48.515312Z] 16:42:48     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T16:42:48.518337Z] 16:42:48     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T16:42:48.520175Z] 16:42:48     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T16:42:48.521959Z] 16:42:48     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T16:42:48.525458Z] 16:42:48     INFO -     get _worker/worker.onmessage@resource://gre/modules/PromiseWorker.jsm:231:9
[task 2017-03-18T16:42:48.527335Z] 16:42:48     INFO -     EventHandlerNonNull*get _worker@resource://gre/modules/PromiseWorker.jsm:217:5
[task 2017-03-18T16:42:48.529172Z] 16:42:48     INFO -     postMessage@resource://gre/modules/PromiseWorker.jsm:291:9
[task 2017-03-18T16:42:48.530977Z] 16:42:48     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-03-18T16:42:48.533002Z] 16:42:48     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T16:42:48.535043Z] 16:42:48     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T16:42:48.537153Z] 16:42:48     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T16:42:48.540064Z] 16:42:48     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T16:42:48.542166Z] 16:42:48     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T16:42:48.544167Z] 16:42:48     INFO -     onError@resource://gre/modules/osfile/osfile_native.jsm:66:7
[task 2017-03-18T16:42:48.546449Z] 16:42:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2017-03-18T16:42:48.550877Z] 16:42:48     INFO - TEST-UNEXPECTED-FAIL | browser/components/sessionstore/test/browser_625016.js | observe1: no closed windows in data written to disk - Got 1, expected 0
[task 2017-03-18T16:42:48.552984Z] 16:42:48     INFO - Stack trace:
[task 2017-03-18T16:42:48.555046Z] 16:42:48     INFO -     chrome://mochikit/content/browser-test.js:test_is:911
[task 2017-03-18T16:42:48.557462Z] 16:42:48     INFO -     chrome://mochitests/content/browser/browser/components/sessionstore/test/browser_625016.js:new_window:40
[task 2017-03-18T16:42:48.561515Z] 16:42:48     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T16:42:48.564020Z] 16:42:48     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T16:42:48.566446Z] 16:42:48     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T16:42:48.569847Z] 16:42:48     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T16:42:48.572737Z] 16:42:48     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T16:42:48.579131Z] 16:42:48     INFO -     get _worker/worker.onmessage@resource://gre/modules/PromiseWorker.jsm:231:9
[task 2017-03-18T16:42:48.581949Z] 16:42:48     INFO -     EventHandlerNonNull*get _worker@resource://gre/modules/PromiseWorker.jsm:217:5
[task 2017-03-18T16:42:48.584857Z] 16:42:48     INFO -     postMessage@resource://gre/modules/PromiseWorker.jsm:291:9
[task 2017-03-18T16:42:48.587090Z] 16:42:48     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-03-18T16:42:48.589777Z] 16:42:48     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T16:42:48.592322Z] 16:42:48     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T16:42:48.594887Z] 16:42:48     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T16:42:48.596807Z] 16:42:48     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T16:42:48.598994Z] 16:42:48     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T16:42:48.600974Z] 16:42:48     INFO -     onError@resource://gre/modules/osfile/osfile_native.jsm:66:7

Comment 1

[Intermittent Failures Robot]

35 failures in 898 pushes (0.039 failures/push) were associated with this bug in the last 7 days. 

This is the #40 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* mozilla-inbound: 15
* autoland: 13
* graphics: 4
* try: 2
* mozilla-central: 1

Platform breakdown:
* linux64: 24
* linux32: 11

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-03-20&endday=2017-03-26&tree=all

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

this started 12 days ago and is occurring >30 times/week.  I am doing retriggers to help narrow this down:
https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=linux%20x64%20debug%20bc12%20e10s&tochange=e02c7b72a4e9e7f6fac1ead658ff36091d761e63&fromchange=b2f781a18186d9330c3ce3e2f5e9a389c566b1a5&selectedJob=87402389

this is linux debug e10s specific.

When I determine the root cause, I will update the bug with what appears to be triggering this.

Mike, in the meantime can you help find someone to look into this so we can reduce the failures or find a fix for this?

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

this is fallout from multi-e10s in bug 1336398.

:mrbkap, could you help narrow this down as this is related to your change?

Comment 4

[Intermittent Failures Robot]

41 failures in 845 pushes (0.049 failures/push) were associated with this bug in the last 7 days. 

This is the #41 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 22
* mozilla-inbound: 11
* try: 5
* mozilla-central: 2
* graphics: 1

Platform breakdown:
* linux64: 24
* linux32: 17

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-03-27&endday=2017-04-02&tree=all

Comment 5

[Mike de Boer [:mikedeboer]]

Joel, since you requested Mike (K.) to look at this, do you still need me to find an additional pair of eyes?

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

I think hearing from :mrbkap is the next best thing- speaking of which, I haven't heard from him in almost a week... :)

Comment 7

[Blake Kaplan (:mrbkap) (inactive)]

It's been a busy week. I looked briefly at this test when you needinfo'd me and didn't see anything immediate. It's on my list to get to, hopefully early next week.

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

thanks, lets touch base mid next week if nothing is obvious for this or you have higher priority things to focus on that re-prioritize this work.

Comment 9

[Intermittent Failures Robot]

51 failures in 867 pushes (0.059 failures/push) were associated with this bug in the last 7 days. 

This is the #35 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 28
* mozilla-inbound: 16
* try: 6
* mozilla-central: 1

Platform breakdown:
* linux32: 35
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-04-03&endday=2017-04-09&tree=all

Comment 10

[Intermittent Failures Robot]

38 failures in 894 pushes (0.043 failures/push) were associated with this bug in the last 7 days. 

This is the #42 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 23
* mozilla-inbound: 10
* try: 3
* mozilla-central: 1
* graphics: 1

Platform breakdown:
* linux32: 23
* linux64: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-04-10&endday=2017-04-16&tree=all

Comment 11

[Joel Maher ( :jmaher ) (UTC -8)]

:mrbkap, it has been 1.5 weeks, any update here?

Comment 12

[Blake Kaplan (:mrbkap) (inactive)]

I looked into this again a little bit ago and don't have much of an answer. It would be a huge help if someone who understands the sessionstore code. My guess is that maybe we start up or shut down a content process when we aren't expecting and that somehow affects when we write out the recovery file? I couldn't find where that happens in the code, though.

I also haven't been able to figure out where we put windows in _closedWindows. Any help would be appreciated.

Comment 13

[Joel Maher ( :jmaher ) (UTC -8)]

:mikedeboer, can you help find someone or look into why session restore tests seem to be affected by multi e10s ?

Comment 14

[Intermittent Failures Robot]

19 failures in 817 pushes (0.023 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 5
* oak: 4
* mozilla-central: 4
* try: 3
* autoland: 3

Platform breakdown:
* linux32: 10
* linux64: 9

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-04-17&endday=2017-04-23&tree=all

Comment 15

[Mike de Boer [:mikedeboer]]

Sorry for the very late reply! :(

I think Mike Conley would be the most appropriate person to have an opinion about ss + multi-process. Good chance he might defer it to someone 'less busy' as well ;)

Comment 16

[Intermittent Failures Robot]

47 failures in 883 pushes (0.053 failures/push) were associated with this bug in the last 7 days. 

This is the #19 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 17
* mozilla-inbound: 14
* try: 7
* mozilla-central: 5
* graphics: 4

Platform breakdown:
* linux64: 32
* linux32: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-04-24&endday=2017-04-30&tree=all

Comment 17

[Mike Conley (:mconley) (:⚙️)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=343ddfe44172

Comment 18

[Mike Conley (:mconley) (:⚙️)]

So the test is failing because the closed window, which the test expects to be in the windows array in the recovery file, is actually in the _closedWindows array instead:

Here's the failing case:

[task 2017-05-02T18:13:22.978998Z] 18:13:22     INFO - GECKO(1094) | mconley: Got recovery file contents: {
[task 2017-05-02T18:13:22.981016Z] 18:13:22     INFO - GECKO(1094) | 	"version": [
[task 2017-05-02T18:13:22.982961Z] 18:13:22     INFO - GECKO(1094) | 		"sessionrestore",
[task 2017-05-02T18:13:22.989409Z] 18:13:22     INFO - GECKO(1094) | 		1
[task 2017-05-02T18:13:22.994300Z] 18:13:22     INFO - GECKO(1094) | 	],
[task 2017-05-02T18:13:22.996277Z] 18:13:22     INFO - GECKO(1094) | 	"windows": [],
[task 2017-05-02T18:13:23.003607Z] 18:13:23     INFO - GECKO(1094) | 	"selectedWindow": 0,
[task 2017-05-02T18:13:23.005610Z] 18:13:23     INFO - GECKO(1094) | 	"_closedWindows": [
[task 2017-05-02T18:13:23.007784Z] 18:13:23     INFO - GECKO(1094) | 		{
[task 2017-05-02T18:13:23.009742Z] 18:13:23     INFO - GECKO(1094) | 			"tabs": [
[task 2017-05-02T18:13:23.014325Z] 18:13:23     INFO - GECKO(1094) | 				{
[task 2017-05-02T18:13:23.016452Z] 18:13:23     INFO - GECKO(1094) | 					"entries": [
[task 2017-05-02T18:13:23.018562Z] 18:13:23     INFO - GECKO(1094) | 						{
[task 2017-05-02T18:13:23.020749Z] 18:13:23     INFO - GECKO(1094) | 							"url": "about:blank",
[task 2017-05-02T18:13:23.030335Z] 18:13:23     INFO - GECKO(1094) | 							"title": "about:blank",
[task 2017-05-02T18:13:23.038444Z] 18:13:23     INFO - GECKO(1094) | 							"charset": "",
[task 2017-05-02T18:13:23.040760Z] 18:13:23     INFO - GECKO(1094) | 							"ID": 117,
[task 2017-05-02T18:13:23.043084Z] 18:13:23     INFO - GECKO(1094) | 							"docshellUUID": "{73a2d235-82b7-4201-adc8-c4df61c11f63}",
[task 2017-05-02T18:13:23.045695Z] 18:13:23     INFO - GECKO(1094) | 							"principalToInherit_base64": "vQZuXxRvRHKDMXv9BbHtkAAAAAAAAAAAwAAAAAAAAEYAAAA4bW96LW51bGxwcmluY2lwYWw6ezYxYWU4ZmNmLWJlMmQtNGY3MC04NGQxLTgxOWMyOWYyOWRkMX0AAAAA",
[task 2017-05-02T18:13:23.050475Z] 18:13:23     INFO - GECKO(1094) | 							"triggeringPrincipal_base64": "SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=",
[task 2017-05-02T18:13:23.052764Z] 18:13:23     INFO - GECKO(1094) | 							"docIdentifier": 117,
[task 2017-05-02T18:13:23.055178Z] 18:13:23     INFO - GECKO(1094) | 							"persist": false
[task 2017-05-02T18:13:23.057441Z] 18:13:23     INFO - GECKO(1094) | 						}
[task 2017-05-02T18:13:23.066323Z] 18:13:23     INFO - GECKO(1094) | 					],
[task 2017-05-02T18:13:23.070365Z] 18:13:23     INFO - GECKO(1094) | 					"lastAccessed": 1493748755071,
[task 2017-05-02T18:13:23.072558Z] 18:13:23     INFO - GECKO(1094) | 					"hidden": false,
[task 2017-05-02T18:13:23.074847Z] 18:13:23     INFO - GECKO(1094) | 					"attributes": {},
[task 2017-05-02T18:13:23.082223Z] 18:13:23     INFO - GECKO(1094) | 					"userContextId": 0,
[task 2017-05-02T18:13:23.086274Z] 18:13:23     INFO - GECKO(1094) | 					"index": 1,
[task 2017-05-02T18:13:23.088411Z] 18:13:23     INFO - GECKO(1094) | 					"image": null,
[task 2017-05-02T18:13:23.090611Z] 18:13:23     INFO - GECKO(1094) | 					"iconLoadingPrincipal": null
[task 2017-05-02T18:13:23.098170Z] 18:13:23     INFO - GECKO(1094) | 				},
[task 2017-05-02T18:13:23.101002Z] 18:13:23     INFO - GECKO(1094) | 				{
[task 2017-05-02T18:13:23.111654Z] 18:13:23     INFO - GECKO(1094) | 					"entries": [
[task 2017-05-02T18:13:23.117625Z] 18:13:23     INFO - GECKO(1094) | 						{
[task 2017-05-02T18:13:23.120019Z] 18:13:23     INFO - GECKO(1094) | 							"url": "http://example.com/browser_625016.js?0.4934403496038583",
[task 2017-05-02T18:13:23.122323Z] 18:13:23     INFO - GECKO(1094) | 							"title": "404 Not Found",
[task 2017-05-02T18:13:23.125798Z] 18:13:23     INFO - GECKO(1094) | 							"charset": "UTF-8",
[task 2017-05-02T18:13:23.130345Z] 18:13:23     INFO - GECKO(1094) | 							"ID": 131,
[task 2017-05-02T18:13:23.132668Z] 18:13:23     INFO - GECKO(1094) | 							"docshellUUID": "{5719eb22-0509-43ea-8923-f69abd97ed25}",
[task 2017-05-02T18:13:23.138361Z] 18:13:23     INFO - GECKO(1094) | 							"originalURI": "http://example.com/browser_625016.js?0.4934403496038583",
[task 2017-05-02T18:13:23.141923Z] 18:13:23     INFO - GECKO(1094) | 							"triggeringPrincipal_base64": "SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=",
[task 2017-05-02T18:13:23.146376Z] 18:13:23     INFO - GECKO(1094) | 							"docIdentifier": 131,
[task 2017-05-02T18:13:23.150340Z] 18:13:23     INFO - GECKO(1094) | 							"persist": true
[task 2017-05-02T18:13:23.152805Z] 18:13:23     INFO - GECKO(1094) | 						}
[task 2017-05-02T18:13:23.162446Z] 18:13:23     INFO - GECKO(1094) | 					],
[task 2017-05-02T18:13:23.170150Z] 18:13:23     INFO - GECKO(1094) | 					"lastAccessed": 1493748746325,
[task 2017-05-02T18:13:23.175251Z] 18:13:23     INFO - GECKO(1094) | 					"hidden": false,
[task 2017-05-02T18:13:23.177449Z] 18:13:23     INFO - GECKO(1094) | 					"attributes": {},
[task 2017-05-02T18:13:23.179974Z] 18:13:23     INFO - GECKO(1094) | 					"image": null,
[task 2017-05-02T18:13:23.183785Z] 18:13:23     INFO - GECKO(1094) | 					"iconLoadingPrincipal": null,
[task 2017-05-02T18:13:23.189667Z] 18:13:23     INFO - GECKO(1094) | 					"userContextId": 0,
[task 2017-05-02T18:13:23.191900Z] 18:13:23     INFO - GECKO(1094) | 					"index": 1
[task 2017-05-02T18:13:23.198243Z] 18:13:23     INFO - GECKO(1094) | 				}
[task 2017-05-02T18:13:23.200365Z] 18:13:23     INFO - GECKO(1094) | 			],
[task 2017-05-02T18:13:23.202597Z] 18:13:23     INFO - GECKO(1094) | 			"selected": 1,
[task 2017-05-02T18:13:23.204753Z] 18:13:23     INFO - GECKO(1094) | 			"_closedTabs": [],
[task 2017-05-02T18:13:23.210340Z] 18:13:23     INFO - GECKO(1094) | 			"width": 1280,
[task 2017-05-02T18:13:23.212602Z] 18:13:23     INFO - GECKO(1094) | 			"height": 1040,
[task 2017-05-02T18:13:23.218257Z] 18:13:23     INFO - GECKO(1094) | 			"screenX": 0,
[task 2017-05-02T18:13:23.220353Z] 18:13:23     INFO - GECKO(1094) | 			"screenY": 0,
[task 2017-05-02T18:13:23.222745Z] 18:13:23     INFO - GECKO(1094) | 			"sizemode": "normal",
[task 2017-05-02T18:13:23.230373Z] 18:13:23     INFO - GECKO(1094) | 			"title": "New Tab",
[task 2017-05-02T18:13:23.234355Z] 18:13:23     INFO - GECKO(1094) | 			"closedAt": 1493748755084,
[task 2017-05-02T18:13:23.237509Z] 18:13:23     INFO - GECKO(1094) | 			"closedId": 170
[task 2017-05-02T18:13:23.239947Z] 18:13:23     INFO - GECKO(1094) | 		}
[task 2017-05-02T18:13:23.250013Z] 18:13:23     INFO - GECKO(1094) | 	],
[task 2017-05-02T18:13:23.252045Z] 18:13:23     INFO - GECKO(1094) | 	"session": {
[task 2017-05-02T18:13:23.254067Z] 18:13:23     INFO - GECKO(1094) | 		"lastUpdate": 1493748756928,
[task 2017-05-02T18:13:23.256186Z] 18:13:23     INFO - GECKO(1094) | 		"startTime": 1493747927402,
[task 2017-05-02T18:13:23.258203Z] 18:13:23     INFO - GECKO(1094) | 		"recentCrashes": 0
[task 2017-05-02T18:13:23.260137Z] 18:13:23     INFO - GECKO(1094) | 	},
[task 2017-05-02T18:13:23.262070Z] 18:13:23     INFO - GECKO(1094) | 	"global": {},
[task 2017-05-02T18:13:23.264131Z] 18:13:23     INFO - GECKO(1094) | 	"cookies": []
[task 2017-05-02T18:13:23.273364Z] 18:13:23     INFO - GECKO(1094) | }

When the test happens to pass, the recovery file is supposed to look like this:

[task 2017-05-02T18:45:46.823007Z] 18:45:46     INFO - GECKO(1085) | mconley: Got recovery file contents: {
[task 2017-05-02T18:45:46.824225Z] 18:45:46     INFO - GECKO(1085) | 	"version": [
[task 2017-05-02T18:45:46.825943Z] 18:45:46     INFO - GECKO(1085) | 		"sessionrestore",
[task 2017-05-02T18:45:46.831078Z] 18:45:46     INFO - GECKO(1085) | 		1
[task 2017-05-02T18:45:46.832287Z] 18:45:46     INFO - GECKO(1085) | 	],
[task 2017-05-02T18:45:46.838248Z] 18:45:46     INFO - GECKO(1085) | 	"windows": [
[task 2017-05-02T18:45:46.840538Z] 18:45:46     INFO - GECKO(1085) | 		{
[task 2017-05-02T18:45:46.842932Z] 18:45:46     INFO - GECKO(1085) | 			"tabs": [
[task 2017-05-02T18:45:46.845435Z] 18:45:46     INFO - GECKO(1085) | 				{
[task 2017-05-02T18:45:46.851056Z] 18:45:46     INFO - GECKO(1085) | 					"entries": [
[task 2017-05-02T18:45:46.853905Z] 18:45:46     INFO - GECKO(1085) | 						{
[task 2017-05-02T18:45:46.859113Z] 18:45:46     INFO - GECKO(1085) | 							"url": "about:blank",
[task 2017-05-02T18:45:46.861613Z] 18:45:46     INFO - GECKO(1085) | 							"title": "about:blank",
[task 2017-05-02T18:45:46.865033Z] 18:45:46     INFO - GECKO(1085) | 							"charset": "",
[task 2017-05-02T18:45:46.867701Z] 18:45:46     INFO - GECKO(1085) | 							"ID": 112,
[task 2017-05-02T18:45:46.874383Z] 18:45:46     INFO - GECKO(1085) | 							"docshellUUID": "{84a8f86f-0014-4c12-939c-386fb75c0c07}",
[task 2017-05-02T18:45:46.877281Z] 18:45:46     INFO - GECKO(1085) | 							"principalToInherit_base64": "vQZuXxRvRHKDMXv9BbHtkAAAAAAAAAAAwAAAAAAAAEYAAAA4bW96LW51bGxwcmluY2lwYWw6e2U5YzVlYTRlLTY0MmMtNGEwMC04ODYwLTk2OTk4NTY1ZDNiN30AAAAA",
[task 2017-05-02T18:45:46.879949Z] 18:45:46     INFO - GECKO(1085) | 							"triggeringPrincipal_base64": "SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=",
[task 2017-05-02T18:45:46.885122Z] 18:45:46     INFO - GECKO(1085) | 							"docIdentifier": 112,
[task 2017-05-02T18:45:46.888803Z] 18:45:46     INFO - GECKO(1085) | 							"persist": false
[task 2017-05-02T18:45:46.891326Z] 18:45:46     INFO - GECKO(1085) | 						}
[task 2017-05-02T18:45:46.895746Z] 18:45:46     INFO - GECKO(1085) | 					],
[task 2017-05-02T18:45:46.900968Z] 18:45:46     INFO - GECKO(1085) | 					"lastAccessed": 1493750667858,
[task 2017-05-02T18:45:46.903368Z] 18:45:46     INFO - GECKO(1085) | 					"hidden": false,
[task 2017-05-02T18:45:46.905756Z] 18:45:46     INFO - GECKO(1085) | 					"attributes": {},
[task 2017-05-02T18:45:46.908380Z] 18:45:46     INFO - GECKO(1085) | 					"userContextId": 0,
[task 2017-05-02T18:45:46.911724Z] 18:45:46     INFO - GECKO(1085) | 					"index": 1,
[task 2017-05-02T18:45:46.914316Z] 18:45:46     INFO - GECKO(1085) | 					"image": null,
[task 2017-05-02T18:45:46.923090Z] 18:45:46     INFO - GECKO(1085) | 					"iconLoadingPrincipal": null
[task 2017-05-02T18:45:46.926644Z] 18:45:46     INFO - GECKO(1085) | 				},
[task 2017-05-02T18:45:46.930152Z] 18:45:46     INFO - GECKO(1085) | 				{
[task 2017-05-02T18:45:46.932452Z] 18:45:46     INFO - GECKO(1085) | 					"entries": [
[task 2017-05-02T18:45:46.936948Z] 18:45:46     INFO - GECKO(1085) | 						{
[task 2017-05-02T18:45:46.939417Z] 18:45:46     INFO - GECKO(1085) | 							"url": "http://example.com/browser_625016.js?0.5879520684804683",
[task 2017-05-02T18:45:46.941920Z] 18:45:46     INFO - GECKO(1085) | 							"title": "404 Not Found",
[task 2017-05-02T18:45:46.944504Z] 18:45:46     INFO - GECKO(1085) | 							"charset": "UTF-8",
[task 2017-05-02T18:45:46.951557Z] 18:45:46     INFO - GECKO(1085) | 							"ID": 133,
[task 2017-05-02T18:45:46.954143Z] 18:45:46     INFO - GECKO(1085) | 							"docshellUUID": "{86d610b6-fc51-4e53-95f9-9ab7dd19a6ef}",
[task 2017-05-02T18:45:46.956794Z] 18:45:46     INFO - GECKO(1085) | 							"originalURI": "http://example.com/browser_625016.js?0.5879520684804683",
[task 2017-05-02T18:45:46.960561Z] 18:45:46     INFO - GECKO(1085) | 							"triggeringPrincipal_base64": "SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=",
[task 2017-05-02T18:45:46.963063Z] 18:45:46     INFO - GECKO(1085) | 							"docIdentifier": 133,
[task 2017-05-02T18:45:46.965713Z] 18:45:46     INFO - GECKO(1085) | 							"persist": true
[task 2017-05-02T18:45:46.983095Z] 18:45:46     INFO - GECKO(1085) | 						}
[task 2017-05-02T18:45:46.985711Z] 18:45:46     INFO - GECKO(1085) | 					],
[task 2017-05-02T18:45:46.991024Z] 18:45:46     INFO - GECKO(1085) | 					"lastAccessed": 1493750662943,
[task 2017-05-02T18:45:46.993420Z] 18:45:46     INFO - GECKO(1085) | 					"hidden": false,
[task 2017-05-02T18:45:46.997054Z] 18:45:46     INFO - GECKO(1085) | 					"attributes": {},
[task 2017-05-02T18:45:46.999815Z] 18:45:46     INFO - GECKO(1085) | 					"userContextId": 0,
[task 2017-05-02T18:45:47.002546Z] 18:45:47     INFO - GECKO(1085) | 					"index": 1,
[task 2017-05-02T18:45:47.005248Z] 18:45:47     INFO - GECKO(1085) | 					"image": null,
[task 2017-05-02T18:45:47.013324Z] 18:45:47     INFO - GECKO(1085) | 					"iconLoadingPrincipal": null
[task 2017-05-02T18:45:47.015865Z] 18:45:47     INFO - GECKO(1085) | 				}
[task 2017-05-02T18:45:47.018366Z] 18:45:47     INFO - GECKO(1085) | 			],
[task 2017-05-02T18:45:47.021938Z] 18:45:47     INFO - GECKO(1085) | 			"selected": 1,
[task 2017-05-02T18:45:47.026516Z] 18:45:47     INFO - GECKO(1085) | 			"_closedTabs": [],
[task 2017-05-02T18:45:47.029618Z] 18:45:47     INFO - GECKO(1085) | 			"width": 1280,
[task 2017-05-02T18:45:47.034571Z] 18:45:47     INFO - GECKO(1085) | 			"height": 1040,
[task 2017-05-02T18:45:47.037042Z] 18:45:47     INFO - GECKO(1085) | 			"screenX": 0,
[task 2017-05-02T18:45:47.044153Z] 18:45:47     INFO - GECKO(1085) | 			"screenY": 0,
[task 2017-05-02T18:45:47.051529Z] 18:45:47     INFO - GECKO(1085) | 			"sizemode": "normal",
[task 2017-05-02T18:45:47.053898Z] 18:45:47     INFO - GECKO(1085) | 			"title": "New Tab",
[task 2017-05-02T18:45:47.056550Z] 18:45:47     INFO - GECKO(1085) | 			"closedAt": 1493750667876,
[task 2017-05-02T18:45:47.062539Z] 18:45:47     INFO - GECKO(1085) | 			"closedId": 169
[task 2017-05-02T18:45:47.066597Z] 18:45:47     INFO - GECKO(1085) | 		}
[task 2017-05-02T18:45:47.071014Z] 18:45:47     INFO - GECKO(1085) | 	],
[task 2017-05-02T18:45:47.074950Z] 18:45:47     INFO - GECKO(1085) | 	"selectedWindow": 0,
[task 2017-05-02T18:45:47.079247Z] 18:45:47     INFO - GECKO(1085) | 	"_closedWindows": [],
[task 2017-05-02T18:45:47.082943Z] 18:45:47     INFO - GECKO(1085) | 	"session": {
[task 2017-05-02T18:45:47.085404Z] 18:45:47     INFO - GECKO(1085) | 		"lastUpdate": 1493750669490,
[task 2017-05-02T18:45:47.095729Z] 18:45:47     INFO - GECKO(1085) | 		"startTime": 1493749639752,
[task 2017-05-02T18:45:47.100209Z] 18:45:47     INFO - GECKO(1085) | 		"recentCrashes": 0
[task 2017-05-02T18:45:47.104374Z] 18:45:47     INFO - GECKO(1085) | 	},
[task 2017-05-02T18:45:47.106508Z] 18:45:47     INFO - GECKO(1085) | 	"global": {},
[task 2017-05-02T18:45:47.108574Z] 18:45:47     INFO - GECKO(1085) | 	"cookies": []
[task 2017-05-02T18:45:47.115997Z] 18:45:47     INFO - GECKO(1085) | }

So that's the problem, but I'm not sure why it's happening. :/ mikedeboer, does that help at all?

Comment 19

[Intermittent Failures Robot]

37 failures in 770 pushes (0.048 failures/push) were associated with this bug in the last 7 days. 

This is the #30 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 16
* mozilla-inbound: 10
* mozilla-central: 5
* graphics: 5
* try: 1

Platform breakdown:
* linux64: 20
* linux32: 16
* windows7-32-vm: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-05-01&endday=2017-05-07&tree=all

Comment 20

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: temporarily disable test on linux/debug

Comment 21

[Geoff Brown [:gbrown]]

Comment on attachment 8867142 [details] [diff] [review]
temporarily disable test on linux/debug

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

It's nice to see Mike and Mike working through this, but yes, without any activity here for the last week, we'd better skip this for now.


Be sure to remove the talos.py change!

::: testing/mozharness/mozharness/mozilla/testing/talos.py
@@ +592,5 @@
>          self.buildbot_status(parser.worst_tbpl_status,
>                               level=parser.worst_log_level)
>  
>      def fetch_python3(self):
> +        print "JMAHER: platform name: %s" % self.config

oops - this shouldn't be here!

Comment 22

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/170489245f63
Intermittent browser/components/sessionstore/test/browser_625016.js. temporarily disable on linux/debug. r=gbrown

Comment 23

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/170489245f63

Comment 24

[Intermittent Failures Robot]

45 failures in 879 pushes (0.051 failures/push) were associated with this bug in the last 7 days. 

This is the #27 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 19
* try: 10
* mozilla-inbound: 7
* mozilla-central: 7
* graphics: 2

Platform breakdown:
* linux32: 24
* linux64: 21

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-05-08&endday=2017-05-14&tree=all

Comment 25

[Intermittent Failures Robot]

1 failures in 892 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-06-19&endday=2017-06-25&tree=all

Comment 26

[Intermittent Failures Robot]

1 failures in 1008 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-07-24&endday=2017-07-30&tree=all

Comment 27

[Intermittent Failures Robot]

2 failures in 888 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-central: 1
* autoland: 1

Platform breakdown:
* linux64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-07-31&endday=2017-08-06&tree=all

Comment 28

[Intermittent Failures Robot]

2 failures in 908 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* oak: 1
* autoland: 1

Platform breakdown:
* windows7-32: 1
* linux64-stylo: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-08-21&endday=2017-08-27&tree=all

Comment 29

[Intermittent Failures Robot]

2 failures in 939 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-esr52: 1
* autoland: 1

Platform breakdown:
* windows7-32-vm: 1
* linux64-stylo: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-08-28&endday=2017-09-03&tree=all

Comment 30

[Intermittent Failures Robot]

1 failures in 762 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-11-13&endday=2017-11-19&tree=all

Comment 31

[Intermittent Failures Robot]

1 failures in 889 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-12-04&endday=2017-12-10&tree=all

Comment 32

[Intermittent Failures Robot]

4 failures in 590 pushes (0.007 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 3
* mozilla-inbound: 1

Platform breakdown:
* linux64: 4

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2017-12-18&endday=2017-12-24&tree=all

Comment 33

[Intermittent Failures Robot]

1 failures in 657 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348583&startday=2018-01-15&endday=2018-01-21&tree=all

Comment 34

[Intermittent Failures Robot]

1 failures in 2672 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1348583&startday=2018-08-13&endday=2018-08-19&tree=all

Comment 35

[Intermittent Failures Robot]

1 failures in 2773 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1348583&startday=2018-09-24&endday=2018-09-30&tree=all

Comment 36

[Intermittent Failures Robot]

1 failures in 2771 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-inbound: 1

Platform breakdown:

• linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1348583&startday=2019-03-11&endday=2019-03-17&tree=all

Comment 37

[Intermittent Failures Robot]

1 failures in 5047 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1348583&startday=2019-08-26&endday=2019-09-01&tree=all

Comment 38

[BugBot [:suhaib / :marco/ :calixte]]

Clear a needinfo that is pending on an inactive user.

Inactive users most likely will not respond; if the missing information is essential and cannot be collected another way, the bug maybe should be closed as INCOMPLETE.

For more information, please visit BugBot documentation.