1504956 - Intermittent testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py TestSessionStoreEnabledNoPrivateWindows.test_with_variety | AssertionError: Non private browsing windows should have

Reporter

Description

•

6 years ago

treeherder

Filed by: ebalazs [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/ZUaxCAaiSNqrnxe0dNwTwA/runs/0/artifacts/public/logs/live_backing.log

[0,197,"WebDriver:GetPageSource",{}]
01:35:45     INFO -  1541496945578	Marionette	TRACE	1 <- [1,197,null,{"value":"<html dir=\"ltr\" lang=\"en\"><head>\n    <title>Mozilla Grants</title>\n    <link rel=\"shortcut icon\ ...     software projects adhere to.\n                </li>\n            </ul>\n        <p></p>\n   </div>\n\n\n</body></html>"}]
01:35:45     INFO -  1541496945579	Marionette	TRACE	1 -> [0,198,"Marionette:SetContext",{"value":"chrome"}]
01:35:45     INFO -  1541496945580	Marionette	TRACE	1 <- [1,198,null,{"value":null}]
01:35:45     INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py TestSessionStoreEnabledNoPrivateWindows.test_with_variety | AssertionError: Non private browsing windows should have
01:35:45     INFO -                          been restored. Expected set([('http://127.0.0.1:50437/layout/mozilla_organizations.html', 'http://127.0.0.1:50437/layout/mozilla_community.html'), ('http://127.0.0.1:50437/layout/mozilla.html',), ('http://127.0.0.1:50437/layout/mozilla_governance.html', 'http://127.0.0.1:50437/layout/mozilla_grants.html')]), got set([(u'http://127.0.0.1:50437/layout/mozilla_governance.html', u'http://127.0.0.1:50437/layout/mozilla_grants.html'), (u'http://127.0.0.1:50437/layout/mozilla.html',), (u'about:blank', u'http://127.0.0.1:50437/layout/mozilla_community.html')]).
01:35:45     INFO - Traceback (most recent call last):
01:35:45     INFO -   File "/Users/cltbld/tasks/task_1541494307/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
01:35:45     INFO -     testMethod()
01:35:45     INFO -   File "/Users/cltbld/tasks/task_1541494307/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py", line 44, in test_with_variety
01:35:45     INFO -     """.format(self.test_windows, current_windows_set))
01:35:45     INFO - TEST-INFO took 17288ms
01:35:45     INFO -  1541496945588	Marionette	TRACE	1 -> [0,199,"Marionette:GetContext",{}]
01:35:45     INFO -  1541496945588	Marionette	TRACE	1 <- [1,199,null,{"value":"chrome"}]
01:35:45     INFO -  1541496945593	Marionette	TRACE	1 -> [0,200,"WebDriver:DeleteSession",{}]
01:35:45     INFO -  1541496945594	Marionette	TRACE	1 <- [1,200,null,{"value":null}]
01:35:45     INFO - Application command: /Users/cltbld/tasks/task_1541494307/build/application/Firefox Nightly.app/Contents/MacOS/firefox -no-remote -marionette -foreground -profile /Users/cltbld/tasks/task_1541494307/build/tmpXLwJMe.mozrunner
01:35:46     INFO -  1541496946235	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
01:35:46     INFO -  1541496946235	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader*
01:35:46     INFO -  1541496946383	Marionette	DEBUG	Received observer notification profile-after-change
01:35:46     INFO -  1541496946433	Marionette	DEBUG	Received observer notification command-line-startup
01:35:46     INFO -  1541496946433	Marionette	DEBUG	Received observer notification nsPref:changed
01:35:46     INFO -  1541496946433	Marionette	DEBUG	Init aborted (running=false, enabled=true, finalUIStartup=false)
01:35:46     INFO -  1541496946659	Marionette	DEBUG	Received observer notification toplevel-window-ready
01:35:47     INFO -  1541496947545	Marionette	DEBUG	Received observer notification sessionstore-windows-restored
01:35:47     INFO -  1541496947546	Marionette	DEBUG	Waiting for delayed startup...
01:35:48     INFO -  1541496948055	Marionette	DEBUG	Waiting for startup tests...
01:35:48     INFO -  1541496948129	Marionette	INFO	Listening on port 2828
01:35:48     INFO -  1541496948130	Marionette	DEBUG	Remote service is active
01:35:48     INFO -  1541496948229	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:51251
01:35:48     INFO -  1541496948238	Marionette	DEBUG	Closed connection 0
01:35:48     INFO -  1541496948239	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:51252
01:35:48     INFO -  1541496948242	Marionette	TRACE	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
01:35:48     INFO -  1541496948488	Marionette	DEBUG	[4294967297] Frame script loaded
01:35:48     INFO -  1541496948489	Marionette	DEBUG	[4294967297] Frame script registered
01:35:48     INFO -  1541496948495	Marionette	TRACE	1 <- [1,1,null,{"sessionId":"5a797e1b-26cd-6d45-9cd8-20866f6379be","capabilities":{"browserName":"firefox","browserVersion":"65.0a ... ld/tmpXLwJMe.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
01:35:48     INFO -  1541496948502	Marionette	TRACE	1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
01:35:48     INFO -  1541496948503	Marionette	TRACE	1 <- [1,2,null,{"value":null}]
01:35:48     INFO -  1541496948509	Marionette	TRACE	1 -> [0,3,"WebDriver:GetChromeWindowHandles",{}]
01:35:48     INFO -  1541496948509	Marionette	TRACE	1 <- [1,3,null,["3"]]
01:35:48     INFO -  1541496948532	Marionette	TRACE	1 -> [0,4,"WebDriver:GetChromeWindowHandle",{}]

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

Updated

•

6 years ago

Comment 4

•

5 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED

Closed: 5 years ago

Resolution: --- → INCOMPLETE

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1504956&startday=2018-12-10&endday=2018-12-16&tree=all

Narcis Beleuzu [:NarcisB]

Updated

•

5 years ago

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* try: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1504956&startday=2018-12-17&endday=2018-12-23&tree=all

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-inbound: 2

Platform breakdown:
* windows7-32: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1504956&startday=2018-12-31&endday=2019-01-06&tree=all

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

5 years ago

OS: Unspecified → Windows 7

Hardware: Unspecified → x86

Comment hidden (Intermittent Failures Robot)

Firefox Bug Husbandry Bot

Comment 14

•

5 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED

Closed: 5 years ago → 5 years ago

Resolution: --- → INCOMPLETE

Comment hidden (Intermittent Failures Robot)

Raul Gurzau (:RaulG)

Comment 16

•

5 years ago

New failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=254234881&repo=mozilla-esr68&lineNumber=47879

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

Firefox Bug Husbandry Bot

Comment 19

•

5 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED

Closed: 5 years ago → 5 years ago

Resolution: --- → INCOMPLETE

Bogdan Tara[:bogdan_tara | bogdant]

Comment 20

•

4 years ago

This is still happening.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=298034620&repo=mozilla-beta&lineNumber=2513

[task 2020-04-17T01:37:47.942Z] 01:37:47     INFO - TEST-START | testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py TestSessionStoreEnabledNoPrivateWindows.test_with_variety
[task 2020-04-17T01:37:47.942Z] 01:37:47     INFO -  1587087467923	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2020-04-17T01:37:47.943Z] 01:37:47     INFO -  1587087467937	Marionette	DEBUG	Closed connection 1
[task 2020-04-17T01:37:47.943Z] 01:37:47     INFO -  1587087467938	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:50558
[task 2020-04-17T01:37:47.949Z] 01:37:47     INFO -  1587087467944	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-04-17T01:37:47.949Z] 01:37:47     INFO -  1587087467945	Marionette	TRACE	[18] Frame script loaded
[task 2020-04-17T01:37:47.949Z] 01:37:47     INFO -  1587087467946	Marionette	TRACE	[18] Frame script registered
[task 2020-04-17T01:37:47.949Z] 01:37:47     INFO -  1587087467947	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"3a48e83a-4cb5-5c4c-b485-583f5cffae4f","capabilities":{"browserName":"firefox","browserVersion":"76.0" ... ld/tmpWI7q5Y.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467955	Marionette	DEBUG	2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467955	Marionette	DEBUG	2 <- [1,2,null,{"value":null}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467956	Marionette	DEBUG	2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467957	Marionette	DEBUG	2 <- [1,3,null,{"value":null}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467959	Marionette	DEBUG	2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467959	Marionette	DEBUG	2 <- [1,4,null,{"value":null}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467960	Marionette	DEBUG	2 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467961	Marionette	DEBUG	2 <- [1,5,null,{"value":"3"}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467962	Marionette	DEBUG	2 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467962	Marionette	DEBUG	2 <- [1,6,null,["3"]]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467963	Marionette	DEBUG	2 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467963	Marionette	DEBUG	2 <- [1,7,null,{"value":"18"}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467964	Marionette	DEBUG	2 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467964	Marionette	DEBUG	2 <- [1,8,null,["18"]]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467965	Marionette	DEBUG	2 -> [0,9,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:47.996Z] 01:37:47     INFO -  1587087467965	Marionette	DEBUG	2 <- [1,9,null,{"value":null}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467966	Marionette	DEBUG	2 -> [0,10,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467966	Marionette	DEBUG	2 <- [1,10,null,{"value":"chrome"}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467967	Marionette	DEBUG	2 -> [0,11,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467967	Marionette	DEBUG	2 <- [1,11,null,{"value":null}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467974	Marionette	DEBUG	2 -> [0,12,"WebDriver:ExecuteScript",{"script":"let prefInterface = Components.classes[\"@mozilla.org/preferences-service;1\"]\n   ... args":[],"filename":"../../venv/lib/python2.7/site-packages/marionette_driver/marionette.py","sandbox":"default","line":842}]
[task 2020-04-17T01:37:47.997Z] 01:37:47     INFO -  1587087467975	Marionette	DEBUG	2 <- [1,12,null,{"value":false}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467976	Marionette	DEBUG	2 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467976	Marionette	DEBUG	2 <- [1,13,null,{"value":null}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467977	Marionette	DEBUG	2 -> [0,14,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467977	Marionette	DEBUG	2 <- [1,14,null,{"value":"chrome"}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467978	Marionette	DEBUG	2 -> [0,15,"WebDriver:DeleteSession",{}]
[task 2020-04-17T01:37:47.998Z] 01:37:47     INFO -  1587087467979	Marionette	DEBUG	2 <- [1,15,null,{"value":null}]
[task 2020-04-17T01:37:48.108Z] 01:37:48     INFO - Application command: /Users/cltbld/tasks/task_1587087308/build/application/Firefox.app/Contents/MacOS/firefox -no-remote -marionette -foreground -profile /Users/cltbld/tasks/task_1587087308/build/tmpIyh7Cx.mozrunner
[task 2020-04-17T01:37:48.821Z] 01:37:48     INFO -  1587087468815	addons.webextension.doh-rollout@mozilla.org	WARN	Loading extension 'doh-rollout@mozilla.org': Reading manifest: Invalid extension permission: networkStatus
[task 2020-04-17T01:37:49.196Z] 01:37:49     INFO -  1587087469182	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2020-04-17T01:37:49.196Z] 01:37:49     INFO -  1587087469182	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
[task 2020-04-17T01:37:49.196Z] 01:37:49     INFO -  1587087469182	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2020-04-17T01:37:49.197Z] 01:37:49     INFO -  1587087469182	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2020-04-17T01:37:49.237Z] 01:37:49     INFO -  1587087469225	Marionette	TRACE	Marionette enabled
[task 2020-04-17T01:37:49.238Z] 01:37:49     INFO -  1587087469226	Marionette	TRACE	Received observer notification profile-after-change
[task 2020-04-17T01:37:49.371Z] 01:37:49     INFO -  1587087469350	Marionette	TRACE	Received observer notification command-line-startup
[task 2020-04-17T01:37:49.528Z] 01:37:49     INFO -  1587087469505	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:37:52.145Z] 01:37:52     INFO -  1587087472126	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2020-04-17T01:37:52.145Z] 01:37:52     INFO -  1587087472126	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2020-04-17T01:37:52.203Z] 01:37:52     INFO -  1587087472187	Marionette	TRACE	All scripts recorded.
[task 2020-04-17T01:37:52.268Z] 01:37:52     INFO -  1587087472251	Marionette	INFO	Listening on port 2828
[task 2020-04-17T01:37:52.268Z] 01:37:52     INFO -  1587087472251	Marionette	DEBUG	Marionette is listening
[task 2020-04-17T01:37:52.291Z] 01:37:52     INFO -  1587087472283	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:50599
[task 2020-04-17T01:37:52.296Z] 01:37:52     INFO -  1587087472289	Marionette	DEBUG	Closed connection 0
[task 2020-04-17T01:37:52.296Z] 01:37:52     INFO -  1587087472290	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:50600
[task 2020-04-17T01:37:52.296Z] 01:37:52     INFO -  1587087472291	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-04-17T01:37:52.328Z] 01:37:52     INFO -  1587087472311	Marionette	TRACE	[18] Frame script loaded
[task 2020-04-17T01:37:52.328Z] 01:37:52     INFO -  1587087472312	Marionette	TRACE	[18] Frame script registered
[task 2020-04-17T01:37:52.328Z] 01:37:52     INFO -  1587087472317	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"42b578e4-8239-654d-910e-5c2ce4875f75","capabilities":{"browserName":"firefox","browserVersion":"76.0" ... ld/tmpIyh7Cx.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-04-17T01:37:52.329Z] 01:37:52     INFO -  1587087472320	Marionette	DEBUG	1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:52.330Z] 01:37:52     INFO -  1587087472320	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2020-04-17T01:37:52.330Z] 01:37:52     INFO -  1587087472323	Marionette	DEBUG	1 -> [0,3,"WebDriver:GetChromeWindowHandle",{}]
[task 2020-04-17T01:37:52.330Z] 01:37:52     INFO -  1587087472323	Marionette	DEBUG	1 <- [1,3,null,{"value":"3"}]
[task 2020-04-17T01:37:52.330Z] 01:37:52     INFO -  1587087472327	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:52.335Z] 01:37:52     INFO -  1587087472332	Marionette	DEBUG	1 <- [1,4,null,{"value":"chrome"}]
[task 2020-04-17T01:37:52.342Z] 01:37:52     INFO -  1587087472335	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"content"}]
[task 2020-04-17T01:37:52.342Z] 01:37:52     INFO -  1587087472335	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2020-04-17T01:37:52.343Z] 01:37:52     INFO -  1587087472339	Marionette	DEBUG	1 -> [0,6,"WebDriver:Navigate",{"url":"http://127.0.0.1:50096/layout/mozilla_governance.html"}]
[task 2020-04-17T01:37:52.366Z] 01:37:52     INFO -  1587087472353	Marionette	TRACE	[18] Received DOM event beforeunload for about:home
[task 2020-04-17T01:37:52.408Z] 01:37:52     INFO -  1587087472388	Marionette	TRACE	[18] Received DOM event pagehide for about:home
[task 2020-04-17T01:37:52.408Z] 01:37:52     INFO -  1587087472393	Marionette	TRACE	[18] Received DOM event unload for about:home
[task 2020-04-17T01:37:52.431Z] 01:37:52     INFO -  1587087472421	Marionette	TRACE	[18] Received DOM event DOMContentLoaded for http://127.0.0.1:50096/layout/mozilla_governance.html
[task 2020-04-17T01:37:52.524Z] 01:37:52     INFO -  1587087472509	Marionette	TRACE	[18] Received DOM event pageshow for http://127.0.0.1:50096/layout/mozilla_governance.html
[task 2020-04-17T01:37:52.524Z] 01:37:52     INFO -  1587087472514	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2020-04-17T01:37:52.541Z] 01:37:52     INFO -  1587087472530	Marionette	DEBUG	1 -> [0,7,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:52.541Z] 01:37:52     INFO -  1587087472531	Marionette	DEBUG	1 <- [1,7,null,["18"]]
[task 2020-04-17T01:37:52.578Z] 01:37:52     INFO -  1587087472546	Marionette	DEBUG	1 -> [0,8,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2020-04-17T01:37:52.578Z] 01:37:52     INFO -  1587087472552	Marionette	TRACE	Received DOM event TabOpen for [object XULElement]
[task 2020-04-17T01:37:53.257Z] 01:37:53     INFO -  1587087473236	Marionette	TRACE	[21] Frame script loaded
[task 2020-04-17T01:37:53.258Z] 01:37:53     INFO -  1587087473238	Marionette	TRACE	[21] Frame script registered
[task 2020-04-17T01:37:53.278Z] 01:37:53     INFO -  1587087473258	Marionette	DEBUG	1 <- [1,8,null,{"handle":"21","type":"tab"}]
[task 2020-04-17T01:37:53.278Z] 01:37:53     INFO -  1587087473260	Marionette	DEBUG	1 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:53.279Z] 01:37:53     INFO -  1587087473261	Marionette	DEBUG	1 <- [1,9,null,["18","21"]]
[task 2020-04-17T01:37:53.279Z] 01:37:53     INFO -  1587087473265	Marionette	DEBUG	1 -> [0,10,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:53.279Z] 01:37:53     INFO -  1587087473265	Marionette	DEBUG	1 <- [1,10,null,["18","21"]]
[task 2020-04-17T01:37:53.280Z] 01:37:53     INFO -  1587087473268	Marionette	DEBUG	1 -> [0,11,"WebDriver:SwitchToWindow",{"handle":"21","focus":true,"name":"21"}]
[task 2020-04-17T01:37:53.306Z] 01:37:53     INFO -  1587087473281	Marionette	TRACE	Received DOM event TabSelect for [object XULElement]
[task 2020-04-17T01:37:53.306Z] 01:37:53     INFO -  1587087473301	Marionette	DEBUG	1 <- [1,11,null,{"value":null}]
[task 2020-04-17T01:37:53.307Z] 01:37:53     INFO -  1587087473305	Marionette	DEBUG	1 -> [0,12,"WebDriver:Navigate",{"url":"http://127.0.0.1:50096/layout/mozilla_grants.html"}]
[task 2020-04-17T01:37:53.351Z] 01:37:53     INFO -  1587087473336	Marionette	TRACE	[21] Received DOM event beforeunload for about:blank
[task 2020-04-17T01:37:53.360Z] 01:37:53     INFO -  1587087473354	Marionette	TRACE	[21] Received DOM event pagehide for about:blank
[task 2020-04-17T01:37:53.413Z] 01:37:53     INFO -  1587087473372	Marionette	TRACE	[21] Received DOM event DOMContentLoaded for http://127.0.0.1:50096/layout/mozilla_grants.html
[task 2020-04-17T01:37:53.413Z] 01:37:53     INFO -  1587087473405	Marionette	TRACE	[21] Received DOM event pageshow for http://127.0.0.1:50096/layout/mozilla_grants.html
[task 2020-04-17T01:37:53.421Z] 01:37:53     INFO -  1587087473411	Marionette	DEBUG	1 <- [1,12,null,{"value":null}]
[task 2020-04-17T01:37:53.426Z] 01:37:53     INFO -  1587087473422	Marionette	DEBUG	1 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:53.426Z] 01:37:53     INFO -  1587087473422	Marionette	DEBUG	1 <- [1,13,null,{"value":null}]
[task 2020-04-17T01:37:53.454Z] 01:37:53     INFO -  1587087473430	Marionette	DEBUG	1 -> [0,14,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:53.454Z] 01:37:53     INFO -  1587087473431	Marionette	DEBUG	1 <- [1,14,null,["3"]]
[task 2020-04-17T01:37:53.454Z] 01:37:53     INFO -  1587087473432	Marionette	DEBUG	1 -> [0,15,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:53.454Z] 01:37:53     INFO -  1587087473432	Marionette	DEBUG	1 <- [1,15,null,["18","21"]]
[task 2020-04-17T01:37:53.454Z] 01:37:53     INFO -  1587087473434	Marionette	DEBUG	1 -> [0,16,"WebDriver:NewWindow",{"type":"window","focus":false,"private":false}]
[task 2020-04-17T01:37:53.459Z] 01:37:53     INFO -  1587087473452	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:37:53.482Z] 01:37:53     INFO -  1587087473468	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:53.482Z] 01:37:53     INFO -  1587087473468	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:53.741Z] 01:37:53     INFO -  1587087473732	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2020-04-17T01:37:53.781Z] 01:37:53     INFO -  1587087473773	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:53.781Z] 01:37:53     INFO -  1587087473775	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:54.123Z] 01:37:54     INFO -  1587087474105	Marionette	DEBUG	1 <- [1,16,null,{"handle":"26","type":"window"}]
[task 2020-04-17T01:37:54.123Z] 01:37:54     INFO -  1587087474107	Marionette	DEBUG	1 -> [0,17,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:54.124Z] 01:37:54     INFO -  1587087474107	Marionette	DEBUG	1 <- [1,17,null,["3","23"]]
[task 2020-04-17T01:37:54.126Z] 01:37:54     INFO -  1587087474123	Marionette	DEBUG	1 -> [0,18,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:54.126Z] 01:37:54     INFO -  1587087474124	Marionette	DEBUG	1 <- [1,18,null,["3","23"]]
[task 2020-04-17T01:37:54.191Z] 01:37:54     INFO -  1587087474135	Marionette	DEBUG	1 -> [0,19,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:54.191Z] 01:37:54     INFO -  1587087474136	Marionette	DEBUG	1 <- [1,19,null,{"value":"chrome"}]
[task 2020-04-17T01:37:54.192Z] 01:37:54     INFO -  1587087474137	Marionette	DEBUG	1 -> [0,20,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:54.192Z] 01:37:54     INFO -  1587087474137	Marionette	DEBUG	1 <- [1,20,null,{"value":null}]
[task 2020-04-17T01:37:54.192Z] 01:37:54     INFO -  1587087474140	Marionette	DEBUG	1 -> [0,21,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/Services.jsm\");\n\n              ... ":"../../venv/lib/python2.7/site-packages/marionette_harness/runner/mixins/window_manager.py","sandbox":"default","line":97}]
[task 2020-04-17T01:37:54.192Z] 01:37:54     INFO -  1587087474142	Marionette	DEBUG	1 <- [1,21,null,{"value":true}]
[task 2020-04-17T01:37:54.192Z] 01:37:54     INFO -  1587087474144	Marionette	DEBUG	1 -> [0,22,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474145	Marionette	DEBUG	1 <- [1,22,null,{"value":null}]
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474146	Marionette	DEBUG	1 -> [0,23,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474146	Marionette	DEBUG	1 <- [1,23,null,{"value":"chrome"}]
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474147	Marionette	DEBUG	1 -> [0,24,"WebDriver:SwitchToWindow",{"handle":"23","focus":true,"name":"23"}]
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474167	Marionette	TRACE	[26] Frame script loaded
[task 2020-04-17T01:37:54.193Z] 01:37:54     INFO -  1587087474168	Marionette	TRACE	[26] Frame script registered
[task 2020-04-17T01:37:54.198Z] 01:37:54     INFO -  1587087474179	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:54.199Z] 01:37:54     INFO -  1587087474179	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:54.256Z] 01:37:54     INFO -  1587087474250	Marionette	DEBUG	1 <- [1,24,null,{"value":null}]
[task 2020-04-17T01:37:54.292Z] 01:37:54     INFO -  1587087474260	Marionette	DEBUG	1 -> [0,25,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:54.292Z] 01:37:54     INFO -  1587087474260	Marionette	DEBUG	1 <- [1,25,null,{"value":"chrome"}]
[task 2020-04-17T01:37:54.292Z] 01:37:54     INFO -  1587087474268	Marionette	DEBUG	1 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2020-04-17T01:37:54.292Z] 01:37:54     INFO -  1587087474269	Marionette	DEBUG	1 <- [1,26,null,{"value":null}]
[task 2020-04-17T01:37:54.292Z] 01:37:54     INFO -  1587087474273	Marionette	DEBUG	1 -> [0,27,"WebDriver:Navigate",{"url":"http://127.0.0.1:50096/layout/mozilla.html"}]
[task 2020-04-17T01:37:54.477Z] 01:37:54     INFO -  1587087474461	Marionette	TRACE	[26] Received DOM event beforeunload for about:home
[task 2020-04-17T01:37:54.559Z] 01:37:54     INFO -  1587087474548	Marionette	TRACE	[26] Received DOM event pagehide for about:home
[task 2020-04-17T01:37:54.561Z] 01:37:54     INFO -  1587087474554	Marionette	TRACE	[26] Received DOM event unload for about:home
[task 2020-04-17T01:37:54.577Z] 01:37:54     INFO -  1587087474566	Marionette	TRACE	[26] Received DOM event DOMContentLoaded for http://127.0.0.1:50096/layout/mozilla.html
[task 2020-04-17T01:37:54.602Z] 01:37:54     INFO -  1587087474588	Marionette	TRACE	[26] Received DOM event pageshow for http://127.0.0.1:50096/layout/mozilla.html
[task 2020-04-17T01:37:54.604Z] 01:37:54     INFO -  1587087474597	Marionette	DEBUG	1 <- [1,27,null,{"value":null}]
[task 2020-04-17T01:37:54.624Z] 01:37:54     INFO -  1587087474614	Marionette	DEBUG	1 -> [0,28,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:54.624Z] 01:37:54     INFO -  1587087474615	Marionette	DEBUG	1 <- [1,28,null,{"value":null}]
[task 2020-04-17T01:37:54.624Z] 01:37:54     INFO -  1587087474616	Marionette	DEBUG	1 -> [0,29,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:54.624Z] 01:37:54     INFO -  1587087474616	Marionette	DEBUG	1 <- [1,29,null,["3","23"]]
[task 2020-04-17T01:37:54.624Z] 01:37:54     INFO -  1587087474617	Marionette	DEBUG	1 -> [0,30,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:54.625Z] 01:37:54     INFO -  1587087474617	Marionette	DEBUG	1 <- [1,30,null,["18","21","26"]]
[task 2020-04-17T01:37:54.625Z] 01:37:54     INFO -  1587087474618	Marionette	DEBUG	1 -> [0,31,"WebDriver:NewWindow",{"type":"window","focus":false,"private":false}]
[task 2020-04-17T01:37:54.648Z] 01:37:54     INFO -  1587087474627	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:37:54.648Z] 01:37:54     INFO -  1587087474632	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:54.648Z] 01:37:54     INFO -  1587087474632	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:54.842Z] 01:37:54     INFO -  1587087474821	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2020-04-17T01:37:54.874Z] 01:37:54     INFO -  1587087474860	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:54.874Z] 01:37:54     INFO -  1587087474860	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:55.308Z] 01:37:55     INFO -  1587087475288	Marionette	DEBUG	1 <- [1,31,null,{"handle":"32","type":"window"}]
[task 2020-04-17T01:37:55.308Z] 01:37:55     INFO -  1587087475293	Marionette	DEBUG	1 -> [0,32,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:55.308Z] 01:37:55     INFO -  1587087475293	Marionette	DEBUG	1 <- [1,32,null,["3","23","29"]]
[task 2020-04-17T01:37:55.308Z] 01:37:55     INFO -  1587087475295	Marionette	DEBUG	1 -> [0,33,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:37:55.308Z] 01:37:55     INFO -  1587087475295	Marionette	DEBUG	1 <- [1,33,null,["3","23","29"]]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475296	Marionette	DEBUG	1 -> [0,34,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475297	Marionette	DEBUG	1 <- [1,34,null,{"value":"chrome"}]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475298	Marionette	DEBUG	1 -> [0,35,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475299	Marionette	DEBUG	1 <- [1,35,null,{"value":null}]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475301	Marionette	DEBUG	1 -> [0,36,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/Services.jsm\");\n\n              ... ":"../../venv/lib/python2.7/site-packages/marionette_harness/runner/mixins/window_manager.py","sandbox":"default","line":97}]
[task 2020-04-17T01:37:55.309Z] 01:37:55     INFO -  1587087475304	Marionette	DEBUG	1 <- [1,36,null,{"value":true}]
[task 2020-04-17T01:37:55.310Z] 01:37:55     INFO -  1587087475305	Marionette	DEBUG	1 -> [0,37,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:55.310Z] 01:37:55     INFO -  1587087475305	Marionette	DEBUG	1 <- [1,37,null,{"value":null}]
[task 2020-04-17T01:37:55.310Z] 01:37:55     INFO -  1587087475306	Marionette	DEBUG	1 -> [0,38,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:55.310Z] 01:37:55     INFO -  1587087475307	Marionette	DEBUG	1 <- [1,38,null,{"value":"chrome"}]
[task 2020-04-17T01:37:55.310Z] 01:37:55     INFO -  1587087475308	Marionette	DEBUG	1 -> [0,39,"WebDriver:SwitchToWindow",{"handle":"29","focus":true,"name":"29"}]
[task 2020-04-17T01:37:55.358Z] 01:37:55     INFO -  1587087475332	Marionette	TRACE	[32] Frame script loaded
[task 2020-04-17T01:37:55.358Z] 01:37:55     INFO -  1587087475333	Marionette	TRACE	[32] Frame script registered
[task 2020-04-17T01:37:55.358Z] 01:37:55     INFO -  1587087475341	Marionette	TRACE	Received DOM event activate for [object ChromeWindow]
[task 2020-04-17T01:37:55.358Z] 01:37:55     INFO -  1587087475342	Marionette	TRACE	Received DOM event focus for [object HTMLDocument]
[task 2020-04-17T01:37:55.408Z] 01:37:55     INFO -  1587087475396	Marionette	DEBUG	1 <- [1,39,null,{"value":null}]
[task 2020-04-17T01:37:55.408Z] 01:37:55     INFO -  1587087475403	Marionette	DEBUG	1 -> [0,40,"Marionette:GetContext",{}]
[task 2020-04-17T01:37:55.408Z] 01:37:55     INFO -  1587087475403	Marionette	DEBUG	1 <- [1,40,null,{"value":"chrome"}]
[task 2020-04-17T01:37:55.409Z] 01:37:55     INFO -  1587087475405	Marionette	DEBUG	1 -> [0,41,"Marionette:SetContext",{"value":"content"}]
[task 2020-04-17T01:37:55.409Z] 01:37:55     INFO -  1587087475406	Marionette	DEBUG	1 <- [1,41,null,{"value":null}]
[task 2020-04-17T01:37:55.411Z] 01:37:55     INFO -  1587087475408	Marionette	DEBUG	1 -> [0,42,"WebDriver:Navigate",{"url":"http://127.0.0.1:50096/layout/mozilla_organizations.html"}]
[task 2020-04-17T01:37:55.536Z] 01:37:55     INFO -  1587087475529	Marionette	TRACE	[32] Received DOM event beforeunload for about:home
[task 2020-04-17T01:37:55.694Z] 01:37:55     INFO -  1587087475675	Marionette	TRACE	[32] Received DOM event pagehide for about:home
[task 2020-04-17T01:37:55.694Z] 01:37:55     INFO -  1587087475681	Marionette	TRACE	[32] Received DOM event unload for about:home
[task 2020-04-17T01:37:55.724Z] 01:37:55     INFO -  1587087475704	Marionette	TRACE	[32] Received DOM event DOMContentLoaded for http://127.0.0.1:50096/layout/mozilla_organizations.html
[task 2020-04-17T01:37:55.748Z] 01:37:55     INFO -  1587087475744	Marionette	TRACE	[32] Received DOM event pageshow for http://127.0.0.1:50096/layout/mozilla_organizations.html
[task 2020-04-17T01:37:55.758Z] 01:37:55     INFO -  1587087475750	Marionette	DEBUG	1 <- [1,42,null,{"value":null}]
[task 2020-04-17T01:37:55.758Z] 01:37:55     INFO -  1587087475755	Marionette	DEBUG	1 -> [0,43,"WebDriver:GetWindowHandles",{}]
[task 2020-04-17T01:37:55.760Z] 01:37:55     INFO -  1587087475755	Marionette	DEBUG	1 <- [1,43,null,["18","21","26","32"]]
...
[task 2020-04-17T01:37:57.031Z] 01:37:57     INFO -  1587087477028	Marionette	DEBUG	1 -> [0,75,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/Services.jsm\");\n                ... args":[],"filename":"../../venv/lib/python2.7/site-packages/marionette_driver/marionette.py","sandbox":"default","line":900}]
[task 2020-04-17T01:37:57.041Z] 01:37:57     INFO -  1587087477031	Marionette	DEBUG	1 <- [1,75,null,{"value":false}]
[task 2020-04-17T01:37:57.041Z] 01:37:57     INFO -  1587087477033	Marionette	DEBUG	1 -> [0,76,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:37:57.042Z] 01:37:57     INFO -  1587087477033	Marionette	DEBUG	1 <- [1,76,null,{"value":null}]
[task 2020-04-17T01:37:57.042Z] 01:37:57     INFO -  1587087477034	Marionette	DEBUG	1 -> [0,77,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2020-04-17T01:37:57.577Z] 01:37:57     INFO -  1587087477549	Marionette	TRACE	Received observer notification quit-application
[task 2020-04-17T01:37:57.577Z] 01:37:57     INFO -  1587087477553	Marionette	DEBUG	1 <- [1,77,null,{"cause":"shutdown"}]
[task 2020-04-17T01:37:57.673Z] 01:37:57     INFO -  1587087477644	Marionette	DEBUG	Closed connection 1
[task 2020-04-17T01:37:58.798Z] 01:37:58     INFO -  1587087478789	Marionette	TRACE	Received observer notification xpcom-will-shutdown
[task 2020-04-17T01:37:58.798Z] 01:37:58     INFO -  1587087478789	Marionette	DEBUG	Marionette stopped listening
[task 2020-04-17T01:37:59.008Z] 01:37:59     INFO - Application command: /Users/cltbld/tasks/task_1587087308/build/application/Firefox.app/Contents/MacOS/firefox -no-remote -marionette -foreground -profile /Users/cltbld/tasks/task_1587087308/build/tmpIyh7Cx.mozrunner
[task 2020-04-17T01:37:59.429Z] 01:37:59     INFO -  1587087479421	Marionette	TRACE	Marionette enabled
[task 2020-04-17T01:37:59.429Z] 01:37:59     INFO -  1587087479421	Marionette	TRACE	Received observer notification profile-after-change
[task 2020-04-17T01:37:59.567Z] 01:37:59     INFO -  1587087479535	Marionette	TRACE	Received observer notification command-line-startup
[task 2020-04-17T01:37:59.636Z] 01:37:59     INFO -  1587087479632	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:38:00.390Z] 01:38:00     INFO -  1587087480383	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:38:00.427Z] 01:38:00     INFO -  1587087480390	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-04-17T01:38:03.468Z] 01:38:03     INFO -  1587087483463	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2020-04-17T01:38:03.468Z] 01:38:03     INFO -  1587087483463	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2020-04-17T01:38:03.699Z] 01:38:03     INFO -  1587087483666	Marionette	TRACE	All scripts recorded.
[task 2020-04-17T01:38:03.744Z] 01:38:03     INFO -  1587087483724	Marionette	INFO	Listening on port 2828
[task 2020-04-17T01:38:03.744Z] 01:38:03     INFO -  1587087483728	Marionette	DEBUG	Marionette is listening
[task 2020-04-17T01:38:03.773Z] 01:38:03     INFO -  1587087483762	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:50664
[task 2020-04-17T01:38:03.808Z] 01:38:03     INFO -  1587087483765	Marionette	DEBUG	Closed connection 0
[task 2020-04-17T01:38:03.808Z] 01:38:03     INFO -  1587087483804	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:50665
[task 2020-04-17T01:38:04.059Z] 01:38:04     INFO -  1587087484048	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-04-17T01:38:04.119Z] 01:38:04     INFO -  1587087484099	Marionette	TRACE	[17] Frame script loaded
[task 2020-04-17T01:38:04.170Z] 01:38:04     INFO -  1587087484161	Marionette	TRACE	[17] Frame script registered
[task 2020-04-17T01:38:04.204Z] 01:38:04     INFO -  1587087484195	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"dbbea8e8-e082-324d-8e54-bc8fb9d371fd","capabilities":{"browserName":"firefox","browserVersion":"76.0" ... ld/tmpIyh7Cx.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-04-17T01:38:04.214Z] 01:38:04     INFO -  1587087484204	Marionette	DEBUG	1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:38:04.215Z] 01:38:04     INFO -  1587087484205	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2020-04-17T01:38:04.215Z] 01:38:04     INFO -  1587087484207	Marionette	DEBUG	1 -> [0,3,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-04-17T01:38:04.215Z] 01:38:04     INFO -  1587087484207	Marionette	DEBUG	1 <- [1,3,null,["3","9","11"]]
[task 2020-04-17T01:38:04.229Z] 01:38:04     INFO -  1587087484218	Marionette	DEBUG	1 -> [0,4,"WebDriver:GetChromeWindowHandle",{}]
[task 2020-04-17T01:38:04.229Z] 01:38:04     INFO -  1587087484219	Marionette	DEBUG	1 <- [1,4,null,{"value":"11"}]
[task 2020-04-17T01:38:04.278Z] 01:38:04     INFO -  1587087484262	Marionette	DEBUG	1 -> [0,5,"Marionette:GetContext",{}]
[task 2020-04-17T01:38:04.278Z] 01:38:04     INFO -  1587087484263	Marionette	DEBUG	1 <- [1,5,null,{"value":"chrome"}]
...
[task 2020-04-17T01:38:05.195Z] 01:38:05     INFO -  1587087485193	Marionette	DEBUG	1 <- [1,30,null,{"value":null}]
[task 2020-04-17T01:38:05.204Z] 01:38:05     INFO -  1587087485196	Marionette	DEBUG	1 -> [0,31,"WebDriver:GetPageSource",{}]
[task 2020-04-17T01:38:05.204Z] 01:38:05     INFO -  1587087485199	Marionette	DEBUG	1 <- [1,31,null,{"value":"<html dir=\"ltr\" lang=\"en\"><head>\n    <title>Mozilla Community</title>\n    <link rel=\"shortcut ico ...  look at the other information referenced\n            throughout this site.\n        </p>\n    </div>\n\n\n</body></html>"}]
[task 2020-04-17T01:38:05.208Z] 01:38:05     INFO -  1587087485205	Marionette	DEBUG	1 -> [0,32,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-17T01:38:05.208Z] 01:38:05     INFO -  1587087485206	Marionette	DEBUG	1 <- [1,32,null,{"value":null}]
[task 2020-04-17T01:38:05.455Z] 01:38:05     INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py TestSessionStoreEnabledNoPrivateWindows.test_with_variety | AssertionError: Non private browsing windows should have
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO -                          been restored. Expected set([('http://127.0.0.1:50096/layout/mozilla_governance.html', 'http://127.0.0.1:50096/layout/mozilla_grants.html'), ('http://127.0.0.1:50096/layout/mozilla.html',), ('http://127.0.0.1:50096/layout/mozilla_organizations.html', 'http://127.0.0.1:50096/layout/mozilla_community.html')]), got set([(u'about:blank', u'http://127.0.0.1:50096/layout/mozilla_grants.html'), (u'http://127.0.0.1:50096/layout/mozilla.html',), (u'http://127.0.0.1:50096/layout/mozilla_organizations.html', u'http://127.0.0.1:50096/layout/mozilla_community.html')]).
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO - Traceback (most recent call last):
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO -   File "/Users/cltbld/tasks/task_1587087308/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO -     testMethod()
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO -   File "/Users/cltbld/tasks/task_1587087308/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/sessionstore/test_restore_windows_after_restart_and_quit.py", line 45, in test_with_variety
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO -     """.format(self.test_windows, current_windows_set))
[task 2020-04-17T01:38:05.456Z] 01:38:05     INFO - TEST-INFO took 17279ms

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 21

•

4 years ago

The problem can be seen here:


The first tab hasn't been completely loaded after the restart and still shows `about:blank` instead of `http://127.0.0.1:50096/layout/mozilla_governance.htm`. Means it skips the wait for page load too early as it looks like.

Mike, who from the sessionstore team can have a look at this? Is Adam still around?

Flags: needinfo?(mdeboer)

Mike de Boer [:mikedeboer]

Comment 22

•

4 years ago

Is this something that has had an increase of occurrences lately?

Flags: needinfo?(mdeboer) → needinfo?(hskupin)

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 24

•

4 years ago

(In reply to Mike de Boer [:mikedeboer] from comment #22)

Is this something that has had an increase of occurrences lately?

No, it's a low rate. So not important right now, but maybe someone might have an idea why sessionstore-windows-restored is fired but not all the windows and tabs have been restored yet.

Flags: needinfo?(hskupin)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

4 years ago

Flags: needinfo?(mdeboer)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

4 years ago

Component: Firefox UI Tests → Session Restore

Product: Testing → Firefox

QA Contact: hskupin

Version: Version 3 → unspecified

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

3 years ago

Status: REOPENED → RESOLVED

Closed: 5 years ago → 3 years ago

Flags: needinfo?(mdeboer)

Resolution: --- → DUPLICATE

Comment hidden (Intermittent Failures Robot)