Closed
Bug 1801001
Opened 2 years ago
Closed 2 years ago
Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_refresh_in_child_frame_navigates_to_top | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Connection timed out after 360.0s)
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Testing
Marionette Client and Harness
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1635776
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=396759741&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EmiqH1IXRuufr4ZkHo4DiA/runs/0/artifacts/public/logs/live_backing.log
[task 2022-11-16T20:01:19.060Z] 20:01:19 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_insecure_error | took 6197ms
[task 2022-11-16T20:01:19.060Z] 20:01:19 INFO - 1668628879058 Marionette DEBUG Closed connection 48
[task 2022-11-16T20:01:19.062Z] 20:01:19 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_refresh_in_child_frame_navigates_to_top
[task 2022-11-16T20:01:19.066Z] 20:01:19 INFO - 1668628879065 Marionette DEBUG Accepted connection 49 from 127.0.0.1:50877
[task 2022-11-16T20:01:19.084Z] 20:01:19 INFO - 1668628879085 Marionette DEBUG 49 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-11-16T20:01:19.088Z] 20:01:19 INFO - 1668628879087 Marionette DEBUG Waiting for initial application window
[task 2022-11-16T20:01:19.093Z] 20:01:19 INFO - 1668628879092 RemoteAgent TRACE [48] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=1600 waitForExplicitStart=false
[task 2022-11-16T20:01:19.093Z] 20:01:19 INFO - 1668628879093 RemoteAgent TRACE [48] ProgressListener Setting unload timer (1600ms)
[task 2022-11-16T20:01:19.094Z] 20:01:19 INFO - 1668628879093 RemoteAgent TRACE [48] Document already finished loading: http://127.0.0.1:49908/test.html
[task 2022-11-16T20:01:19.094Z] 20:01:19 INFO - 1668628879093 RemoteAgent TRACE [48] ProgressListener Stop: has error=false
[task 2022-11-16T20:01:19.100Z] 20:01:19 INFO - 1668628879098 Marionette DEBUG 49 <- [1,1,null,{"sessionId":"59916094-e6a6-49dc-9895-a74158791ed1","capabilities":{"browserName":"firefox","browserVersion":"108.0","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20221116190415","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":8724,"moz:profile":"C:\\Users\\task_166862154791591\\AppData\\Local\\Temp\\tmpicscb86_.mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2022-11-16T20:01:19.100Z] 20:01:19 INFO - 1668628879100 Marionette DEBUG 49 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2022-11-16T20:01:19.100Z] 20:01:19 INFO - 1668628879100 Marionette DEBUG 49 <- [1,2,null,{"value":null}]
[task 2022-11-16T20:01:19.102Z] 20:01:19 INFO - 1668628879102 Marionette DEBUG 49 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2022-11-16T20:01:19.102Z] 20:01:19 INFO - 1668628879102 Marionette DEBUG 49 <- [1,3,null,{"value":null}]
[task 2022-11-16T20:01:19.104Z] 20:01:19 INFO - 1668628879104 Marionette DEBUG 49 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2022-11-16T20:01:19.104Z] 20:01:19 INFO - 1668628879104 Marionette DEBUG 49 <- [1,4,null,{"value":null}]
[task 2022-11-16T20:01:19.107Z] 20:01:19 INFO - 1668628879106 Marionette DEBUG 49 -> [0,5,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:19.107Z] 20:01:19 INFO - 1668628879107 Marionette DEBUG 49 <- [1,5,null,{"value":"content"}]
[task 2022-11-16T20:01:19.109Z] 20:01:19 INFO - 1668628879108 Marionette DEBUG 49 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-11-16T20:01:19.109Z] 20:01:19 INFO - 1668628879109 Marionette DEBUG 49 <- [1,6,null,{"value":null}]
[task 2022-11-16T20:01:19.110Z] 20:01:19 INFO - 1668628879110 Marionette DEBUG 49 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2022-11-16T20:01:19.111Z] 20:01:19 INFO - 1668628879111 Marionette DEBUG 49 <- [1,7,null,{"value":"5e437e26-2217-411f-9b7b-cb23fde79706"}]
[task 2022-11-16T20:01:19.113Z] 20:01:19 INFO - 1668628879112 Marionette DEBUG 49 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.113Z] 20:01:19 INFO - 1668628879112 Marionette DEBUG 49 <- [1,8,null,{"value":null}]
[task 2022-11-16T20:01:19.114Z] 20:01:19 INFO - 1668628879114 Marionette DEBUG 49 -> [0,9,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:19.114Z] 20:01:19 INFO - 1668628879114 Marionette DEBUG 49 <- [1,9,null,{"value":"content"}]
[task 2022-11-16T20:01:19.115Z] 20:01:19 INFO - 1668628879115 Marionette DEBUG 49 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-11-16T20:01:19.115Z] 20:01:19 INFO - 1668628879115 Marionette DEBUG 49 <- [1,10,null,{"value":null}]
[task 2022-11-16T20:01:19.116Z] 20:01:19 INFO - 1668628879116 Marionette DEBUG 49 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:01:19.117Z] 20:01:19 INFO - 1668628879117 Marionette DEBUG 49 <- [1,11,null,["5e437e26-2217-411f-9b7b-cb23fde79706"]]
[task 2022-11-16T20:01:19.118Z] 20:01:19 INFO - 1668628879118 Marionette DEBUG 49 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.118Z] 20:01:19 INFO - 1668628879118 Marionette DEBUG 49 <- [1,12,null,{"value":null}]
[task 2022-11-16T20:01:19.119Z] 20:01:19 INFO - 1668628879119 Marionette DEBUG 49 -> [0,13,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:19.120Z] 20:01:19 INFO - 1668628879119 Marionette DEBUG 49 <- [1,13,null,{"value":"content"}]
[task 2022-11-16T20:01:19.121Z] 20:01:19 INFO - 1668628879120 Marionette DEBUG 49 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.121Z] 20:01:19 INFO - 1668628879121 Marionette DEBUG 49 <- [1,14,null,{"value":null}]
[task 2022-11-16T20:01:19.122Z] 20:01:19 INFO - 1668628879122 Marionette DEBUG 49 -> [0,15,"WebDriver:GetWindowHandle",{}]
[task 2022-11-16T20:01:19.123Z] 20:01:19 INFO - 1668628879123 Marionette DEBUG 49 <- [1,15,null,{"value":"6f2c66d2-2d93-4a74-a15a-afcddbe648bc"}]
[task 2022-11-16T20:01:19.123Z] 20:01:19 INFO - 1668628879124 Marionette DEBUG 49 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.124Z] 20:01:19 INFO - 1668628879124 Marionette DEBUG 49 <- [1,16,null,{"value":null}]
[task 2022-11-16T20:01:19.125Z] 20:01:19 INFO - 1668628879125 Marionette DEBUG 49 -> [0,17,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:19.126Z] 20:01:19 INFO - 1668628879126 Marionette DEBUG 49 <- [1,17,null,{"value":"content"}]
[task 2022-11-16T20:01:19.127Z] 20:01:19 INFO - 1668628879127 Marionette DEBUG 49 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.128Z] 20:01:19 INFO - 1668628879127 Marionette DEBUG 49 <- [1,18,null,{"value":null}]
[task 2022-11-16T20:01:19.128Z] 20:01:19 INFO - 1668628879131 Marionette DEBUG 49 -> [0,19,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:01:19.132Z] 20:01:19 INFO - 1668628879133 Marionette DEBUG 49 <- [1,19,null,["6f2c66d2-2d93-4a74-a15a-afcddbe648bc"]]
[task 2022-11-16T20:01:19.136Z] 20:01:19 INFO - 1668628879136 Marionette DEBUG 49 -> [0,20,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.138Z] 20:01:19 INFO - 1668628879137 Marionette DEBUG 49 <- [1,20,null,{"value":null}]
[task 2022-11-16T20:01:19.139Z] 20:01:19 INFO - 1668628879143 Marionette DEBUG 49 -> [0,21,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:19.144Z] 20:01:19 INFO - 1668628879143 Marionette DEBUG 49 <- [1,21,null,{"value":"content"}]
[task 2022-11-16T20:01:19.144Z] 20:01:19 INFO - 1668628879145 Marionette DEBUG 49 -> [0,22,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.144Z] 20:01:19 INFO - 1668628879145 Marionette DEBUG 49 <- [1,22,null,{"value":null}]
[task 2022-11-16T20:01:19.146Z] 20:01:19 INFO - 1668628879147 Marionette DEBUG 49 -> [0,23,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:01:19.149Z] 20:01:19 INFO - 1668628879148 Marionette DEBUG 49 <- [1,23,null,["6f2c66d2-2d93-4a74-a15a-afcddbe648bc"]]
[task 2022-11-16T20:01:19.150Z] 20:01:19 INFO - 1668628879150 Marionette DEBUG 49 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:19.157Z] 20:01:19 INFO - 1668628879157 Marionette DEBUG 49 <- [1,24,null,{"value":null}]
[task 2022-11-16T20:01:19.159Z] 20:01:19 INFO - 1668628879162 Marionette DEBUG 49 -> [0,25,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2022-11-16T20:01:19.249Z] 20:01:19 INFO - 1668628879251 RemoteAgent TRACE Received DOM event TabOpen for [object XULElement]
[task 2022-11-16T20:01:19.623Z] 20:01:19 INFO - 1668628879623 RemoteAgent TRACE [84] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=1600 waitForExplicitStart=false
[task 2022-11-16T20:01:19.627Z] 20:01:19 INFO - 1668628879624 RemoteAgent TRACE [84] ProgressListener Setting unload timer (1600ms)
[task 2022-11-16T20:01:19.705Z] 20:01:19 INFO - 1668628879705 RemoteAgent TRACE [84] ProgressListener Check loading state: isStart=1 isStop=0
[task 2022-11-16T20:01:19.705Z] 20:01:19 INFO - 1668628879706 RemoteAgent TRACE [84] ProgressListener state=start: about:blank
[task 2022-11-16T20:01:19.705Z] 20:01:19 INFO - 1668628879706 RemoteAgent TRACE [84] ProgressListener Cleared the unload timer
[task 2022-11-16T20:01:19.725Z] 20:01:19 INFO - 1668628879727 RemoteAgent TRACE [84] ProgressListener Check loading state: isStart=0 isStop=16
[task 2022-11-16T20:01:19.732Z] 20:01:19 INFO - 1668628879727 RemoteAgent TRACE [84] ProgressListener Ignore aborted navigation error to the initial document, real document will be loaded.
[task 2022-11-16T20:01:19.735Z] 20:01:19 INFO - 1668628879734 RemoteAgent TRACE [84] ProgressListener Check loading state: isStart=1 isStop=0
[task 2022-11-16T20:01:19.993Z] 20:01:19 INFO - 1668628879997 RemoteAgent TRACE [84] ProgressListener Check loading state: isStart=0 isStop=16
[task 2022-11-16T20:01:19.993Z] 20:01:19 INFO - 1668628879998 RemoteAgent TRACE [84] ProgressListener state=stop: about:blank
[task 2022-11-16T20:01:20.000Z] 20:01:20 INFO - 1668628879998 RemoteAgent TRACE [84] ProgressListener Stop: has error=false
[task 2022-11-16T20:01:20.001Z] 20:01:20 INFO - 1668628880001 Marionette DEBUG 49 <- [1,25,null,{"handle":"65cb633d-7f74-401d-a5b7-7f859bb574b5","type":"tab"}]
[task 2022-11-16T20:01:20.005Z] 20:01:20 INFO - 1668628880004 Marionette DEBUG 49 -> [0,26,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:20.006Z] 20:01:20 INFO - 1668628880005 Marionette DEBUG 49 <- [1,26,null,{"value":"content"}]
[task 2022-11-16T20:01:20.011Z] 20:01:20 INFO - 1668628880010 Marionette DEBUG 49 -> [0,27,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:20.011Z] 20:01:20 INFO - 1668628880011 Marionette DEBUG 49 <- [1,27,null,{"value":null}]
[task 2022-11-16T20:01:20.014Z] 20:01:20 INFO - 1668628880014 Marionette DEBUG 49 -> [0,28,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:01:20.015Z] 20:01:20 INFO - 1668628880015 Marionette DEBUG 49 <- [1,28,null,["6f2c66d2-2d93-4a74-a15a-afcddbe648bc","65cb633d-7f74-401d-a5b7-7f859bb574b5"]]
[task 2022-11-16T20:01:20.019Z] 20:01:20 INFO - 1668628880019 Marionette DEBUG 49 -> [0,29,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:20.020Z] 20:01:20 INFO - 1668628880020 Marionette DEBUG 49 <- [1,29,null,{"value":null}]
[task 2022-11-16T20:01:20.023Z] 20:01:20 INFO - 1668628880023 Marionette DEBUG 49 -> [0,30,"Marionette:GetContext",{}]
[task 2022-11-16T20:01:20.024Z] 20:01:20 INFO - 1668628880024 Marionette DEBUG 49 <- [1,30,null,{"value":"content"}]
[task 2022-11-16T20:01:20.027Z] 20:01:20 INFO - 1668628880026 Marionette DEBUG 49 -> [0,31,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:20.027Z] 20:01:20 INFO - 1668628880026 Marionette DEBUG 49 <- [1,31,null,{"value":null}]
[task 2022-11-16T20:01:20.028Z] 20:01:20 INFO - 1668628880028 Marionette DEBUG 49 -> [0,32,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:01:20.028Z] 20:01:20 INFO - 1668628880028 Marionette DEBUG 49 <- [1,32,null,["6f2c66d2-2d93-4a74-a15a-afcddbe648bc","65cb633d-7f74-401d-a5b7-7f859bb574b5"]]
[task 2022-11-16T20:01:20.030Z] 20:01:20 INFO - 1668628880030 Marionette DEBUG 49 -> [0,33,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:01:20.030Z] 20:01:20 INFO - 1668628880030 Marionette DEBUG 49 <- [1,33,null,{"value":null}]
[task 2022-11-16T20:01:20.031Z] 20:01:20 INFO - 1668628880032 Marionette DEBUG 49 -> [0,34,"WebDriver:SwitchToWindow",{"handle":"65cb633d-7f74-401d-a5b7-7f859bb574b5","focus":true}]
[task 2022-11-16T20:01:20.064Z] 20:01:20 INFO - 1668628880070 RemoteAgent TRACE Received DOM event TabSelect for [object XULElement]
[task 2022-11-16T20:01:20.260Z] 20:01:20 INFO - 1668628880256 Marionette DEBUG 49 <- [1,34,null,{"value":null}]
[task 2022-11-16T20:01:20.280Z] 20:01:20 INFO - 1668628880282 Marionette DEBUG 49 -> [0,35,"WebDriver:GetTimeouts",{}]
[task 2022-11-16T20:01:20.280Z] 20:01:20 INFO - 1668628880283 Marionette DEBUG 49 <- [1,35,null,{"implicit":0,"pageLoad":300000,"script":30000}]
[task 2022-11-16T20:01:20.290Z] 20:01:20 INFO - 1668628880288 Marionette DEBUG 49 -> [0,36,"WebDriver:ExecuteScript",{"script":"return window.history.length;","args":[],"newSandbox":true,"sandbox":"default","line":73,"filename":"Z:\\task_166862154791591\\build\\tests\\marionette\\tests\\testing\\marionette\\harness\\marionette_harness\\tests\\unit\\test_navigation.py"}]
[task 2022-11-16T20:01:20.309Z] 20:01:20 INFO - DEBUG: Adding blocker ContentParent: id=1284bd53f580 for phase xpcom-will-shutdown
[task 2022-11-16T20:01:20.309Z] 20:01:20 INFO - DEBUG: Adding blocker ContentParent: id=1284bd53f580 for phase profile-before-change
[task 2022-11-16T20:01:20.311Z] 20:01:20 INFO - DEBUG: Adding blocker ContentParent: id=1284bd53f580 for phase quit-application-granted
[task 2022-11-16T20:01:20.373Z] 20:01:20 INFO - 1668628880366 Marionette TRACE [84] MarionetteCommands actor created for window id 139586437121
[task 2022-11-16T20:01:20.456Z] 20:01:20 INFO - 1668628880449 Marionette DEBUG 49 <- [1,36,null,{"value":1}]
[task 2022-11-16T20:01:20.467Z] 20:01:20 INFO - 1668628880464 Marionette DEBUG 49 -> [0,37,"WebDriver:Navigate",{"url":"http://127.0.0.1:49908/frameset.html"}]
[task 2022-11-16T20:01:20.516Z] 20:01:20 INFO - 1668628880509 Marionette TRACE [84] Received event beforeunload for about:blank
[task 2022-11-16T20:01:20.652Z] 20:01:20 INFO - 1668628880644 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 85
[task 2022-11-16T20:01:20.848Z] 20:01:20 INFO - 1668628880843 Marionette TRACE [85] Received event beforeunload for about:blank
[task 2022-11-16T20:01:20.879Z] 20:01:20 INFO - 1668628880876 Marionette TRACE [85] Received event pagehide for about:blank
[task 2022-11-16T20:01:21.560Z] 20:01:21 INFO - 1668628881547 Marionette TRACE [85] Received event DOMContentLoaded for http://127.0.0.1:49908/frameset.html
[task 2022-11-16T20:01:21.840Z] 20:01:21 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:01:21.868Z] 20:01:21 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:01:21.876Z] 20:01:21 INFO - DEBUG: Adding blocker ContentParent: id=1284bcd79580 for phase xpcom-will-shutdown
[task 2022-11-16T20:01:21.876Z] 20:01:21 INFO - DEBUG: Adding blocker ContentParent: id=1284bcd79580 for phase profile-before-change
[task 2022-11-16T20:01:21.878Z] 20:01:21 INFO - DEBUG: Adding blocker ContentParent: id=1284bcd79580 for phase quit-application-granted
[task 2022-11-16T20:01:21.901Z] 20:01:21 INFO - WARNING | IO Completion Port failed to signal process shutdown
[task 2022-11-16T20:01:21.904Z] 20:01:21 INFO - Parent process 4280 exited with children alive:
[task 2022-11-16T20:01:21.904Z] 20:01:21 INFO - PIDS: 9076, 8724, 5444, 3076, 7504, 8792, 5732, 5932, 3328, 5720
[task 2022-11-16T20:01:21.904Z] 20:01:21 INFO - Attempting to kill them, but no guarantee of success
[task 2022-11-16T20:07:20.533Z] 20:07:20 ERROR - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_refresh_in_child_frame_navigates_to_top | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Connection timed out after 360.0s)
[task 2022-11-16T20:07:20.548Z] 20:07:20 INFO - Traceback (most recent call last):
[task 2022-11-16T20:07:20.548Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 202, in run
[task 2022-11-16T20:07:20.550Z] 20:07:20 INFO - testMethod()
[task 2022-11-16T20:07:20.554Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 671, in test_refresh_in_child_frame_navigates_to_top
[task 2022-11-16T20:07:20.560Z] 20:07:20 INFO - self.marionette.navigate(self.test_page_frameset)
[task 2022-11-16T20:07:20.562Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1597, in navigate
[task 2022-11-16T20:07:20.564Z] 20:07:20 INFO - self._send_message("WebDriver:Navigate", {"url": url})
[task 2022-11-16T20:07:20.566Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\decorators.py", line 37, in _
[task 2022-11-16T20:07:20.568Z] 20:07:20 INFO - m._handle_socket_failure()
[task 2022-11-16T20:07:20.568Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\marionette.py", line 745, in _handle_socket_failure
[task 2022-11-16T20:07:20.569Z] 20:07:20 INFO - reraise(
[task 2022-11-16T20:07:20.570Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2022-11-16T20:07:20.571Z] 20:07:20 INFO - raise value.with_traceback(tb)
[task 2022-11-16T20:07:20.572Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\decorators.py", line 27, in _
[task 2022-11-16T20:07:20.572Z] 20:07:20 INFO - return func(*args, **kwargs)
[task 2022-11-16T20:07:20.580Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\marionette.py", line 661, in _send_message
[task 2022-11-16T20:07:20.580Z] 20:07:20 INFO - msg = self.client.request(name, params)
[task 2022-11-16T20:07:20.580Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\transport.py", line 383, in request
[task 2022-11-16T20:07:20.588Z] 20:07:20 INFO - return self.receive()
[task 2022-11-16T20:07:20.588Z] 20:07:20 INFO - File "Z:\task_166862154791591\build\venv\lib\site-packages\marionette_driver\transport.py", line 220, in receive
[task 2022-11-16T20:07:20.588Z] 20:07:20 INFO - raise socket.timeout(
[task 2022-11-16T20:07:20.589Z] 20:07:20 INFO - TEST-INFO took 361441ms
[task 2022-11-16T20:07:20.590Z] 20:07:20 INFO - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_refresh_in_child_frame_navigates_to_top logged while not in progress. Logged with data: {"message": "marionette_driver.errors.InvalidSessionIdException: Please start a session", "expected": "PASS", "stack": "Traceback (most recent call last):\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_harness\\marionette_test\\testcases.py\", line 235, in run\n self.tearDown()\n File \"Z:\\task_166862154791591\\build\\tests\\marionette\\tests\\testing\\marionette\\harness\\marionette_harness\\tests\\unit\\test_navigation.py\", line 65, in tearDown\n self.marionette.timeout.reset()\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 104, in reset\n self.script = DEFAULT_SCRIPT_TIMEOUT\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 57, in script\n self._set(\"script\", sec)\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 33, in _set\n self._marionette._send_message(\"WebDriver:SetTimeouts\", {name: ms})\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 27, in _\n return func(*args, **kwargs)\n File \"Z:\\task_166862154791591\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 658, in _send_message\n raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_navigation.TestRefresh", "method_name": "test_refresh_in_child_frame_navigates_to_top"}, "test": "testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_refresh_in_child_frame_navigates_to_top", "status": "ERROR"}
[task 2022-11-16T20:07:20.601Z] 20:07:20 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestRefresh.test_timeout_error
[task 2022-11-16T20:07:20.610Z] 20:07:20 INFO - Application command: Z:\task_166862154791591\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_166862154791591\AppData\Local\Temp\tmpicscb86_.mozrunner
[task 2022-11-16T20:07:32.503Z] 20:07:32 INFO - DEBUG: Adding blocker PermissionManager: Flushing data for phase xpcom-will-shutdown
[task 2022-11-16T20:07:33.460Z] 20:07:33 INFO - DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2022-11-16T20:07:33.842Z] 20:07:33 INFO - DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase profile-before-change
[task 2022-11-16T20:07:33.863Z] 20:07:33 INFO - DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase profile-before-change-telemetry
[task 2022-11-16T20:07:33.863Z] 20:07:33 INFO - DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2022-11-16T20:07:33.868Z] 20:07:33 INFO - DEBUG: Adding blocker IOUtils Blocker (xpcom-will-shutdown) for phase xpcom-will-shutdown
[task 2022-11-16T20:07:33.871Z] 20:07:33 INFO - DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase IOUtils: waiting for xpcomWillShutdown IO to complete
[task 2022-11-16T20:07:34.008Z] 20:07:34 INFO - DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2022-11-16T20:07:34.045Z] 20:07:34 INFO - DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2022-11-16T20:07:34.061Z] 20:07:34 INFO - DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2022-11-16T20:07:34.082Z] 20:07:34 INFO - DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change and awaiting all checkpoints written for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:07:34.256Z] 20:07:34 INFO - DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2022-11-16T20:07:34.337Z] 20:07:34 INFO - DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2022-11-16T20:07:34.381Z] 20:07:34 INFO - DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2022-11-16T20:07:34.405Z] 20:07:34 INFO - DEBUG: Adding blocker TerminatoryTelemetry: Waiting to submit telemetry for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2022-11-16T20:07:34.425Z] 20:07:34 INFO - 1668629254430 Marionette INFO Marionette enabled
[task 2022-11-16T20:07:34.444Z] 20:07:34 INFO - 1668629254442 Marionette TRACE Received observer notification final-ui-startup
[task 2022-11-16T20:07:34.453Z] 20:07:34 INFO - 1668629254452 Marionette INFO Listening on port 2828
[task 2022-11-16T20:07:34.454Z] 20:07:34 INFO - 1668629254454 Marionette DEBUG Marionette is listening
[task 2022-11-16T20:07:34.939Z] 20:07:34 INFO - DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2022-11-16T20:07:35.162Z] 20:07:35 INFO - 1668629255159 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50911
[task 2022-11-16T20:07:35.181Z] 20:07:35 INFO - 1668629255180 Marionette DEBUG Accepted connection 1 from 127.0.0.1:50912
[task 2022-11-16T20:07:35.215Z] 20:07:35 INFO - 1668629255218 Marionette DEBUG Closed connection 0
[task 2022-11-16T20:07:35.251Z] 20:07:35 INFO - 1668629255251 Marionette DEBUG Closed connection 1
[task 2022-11-16T20:07:35.258Z] 20:07:35 INFO - 1668629255255 Marionette DEBUG Accepted connection 2 from 127.0.0.1:50913
[task 2022-11-16T20:07:36.178Z] 20:07:36 INFO - DEBUG: Adding blocker JSON store: writing data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:07:36.795Z] 20:07:36 INFO - DEBUG: Adding blocker MediaShutdownManager: shutdown for phase profile-before-change
[task 2022-11-16T20:07:37.108Z] 20:07:37 INFO - DEBUG: Adding blocker JSON store: writing data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:07:37.172Z] 20:07:37 INFO - 1668629257177 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-11-16T20:07:37.200Z] 20:07:37 INFO - 1668629257198 Marionette DEBUG Waiting for initial application window
[task 2022-11-16T20:07:37.952Z] 20:07:37 INFO - DEBUG: Completed blocker TerminatoryTelemetry: Waiting to submit telemetry for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2022-11-16T20:07:39.045Z] 20:07:39 INFO - DEBUG: Adding blocker ContentParent: id=1265a9ca8580 for phase xpcom-will-shutdown
[task 2022-11-16T20:07:39.061Z] 20:07:39 INFO - DEBUG: Adding blocker ContentParent: id=1265a9ca8580 for phase profile-before-change
[task 2022-11-16T20:07:39.065Z] 20:07:39 INFO - DEBUG: Adding blocker ContentParent: id=1265a9ca8580 for phase quit-application-granted
[task 2022-11-16T20:07:39.124Z] 20:07:39 INFO - DEBUG: Adding blocker SitePermsAddonProvider for phase AddonManager: Waiting for providers to shut down.
[task 2022-11-16T20:07:39.182Z] 20:07:39 INFO - DEBUG: Adding blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2022-11-16T20:07:40.091Z] 20:07:40 INFO - DEBUG: Adding blocker ServiceWorkerShutdownBlocker: shutting down Service Workers for phase profile-change-teardown
[task 2022-11-16T20:07:45.202Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d80980 for phase xpcom-will-shutdown
[task 2022-11-16T20:07:45.206Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d80980 for phase profile-before-change
[task 2022-11-16T20:07:45.208Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d80980 for phase quit-application-granted
[task 2022-11-16T20:07:45.379Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d82c80 for phase xpcom-will-shutdown
[task 2022-11-16T20:07:45.379Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d82c80 for phase profile-before-change
[task 2022-11-16T20:07:45.379Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d82c80 for phase quit-application-granted
[task 2022-11-16T20:07:45.505Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d84a80 for phase xpcom-will-shutdown
[task 2022-11-16T20:07:45.509Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d84a80 for phase profile-before-change
[task 2022-11-16T20:07:45.513Z] 20:07:45 INFO - DEBUG: Adding blocker ContentParent: id=1265a9d84a80 for phase quit-application-granted
[task 2022-11-16T20:07:48.825Z] 20:07:48 INFO - DEBUG: Adding blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2022-11-16T20:07:49.160Z] 20:07:49 INFO - DEBUG: Adding blocker Places Clients shutdown for phase profile-change-teardown
[task 2022-11-16T20:07:49.194Z] 20:07:49 INFO - DEBUG: Adding blocker Places Connection shutdown for phase profile-before-change
[task 2022-11-16T20:07:49.426Z] 20:07:49 INFO - DEBUG: Adding blocker JSON store: writing data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:07:50.921Z] 20:07:50 INFO - DEBUG: Adding blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2022-11-16T20:07:56.121Z] 20:07:56 INFO - DEBUG: Adding blocker Sqlite.sys.mjs shutdown blocker for phase profile-before-change
[task 2022-11-16T20:07:56.133Z] 20:07:56 INFO - DEBUG: Adding blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2022-11-16T20:07:56.145Z] 20:07:56 INFO - DEBUG: Adding blocker Closing ContentPrefService2 connection. for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2022-11-16T20:07:56.612Z] 20:07:56 INFO - DEBUG: Adding blocker JSON store: writing data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:07:58.076Z] 20:07:58 INFO - DEBUG: Adding blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-11-16T20:07:59.915Z] 20:07:59 INFO - DEBUG: Adding blocker ContentParent: id=1265a9f91580 for phase xpcom-will-shutdown
[task 2022-11-16T20:07:59.915Z] 20:07:59 INFO - DEBUG: Adding blocker ContentParent: id=1265a9f91580 for phase profile-before-change
[task 2022-11-16T20:07:59.919Z] 20:07:59 INFO - DEBUG: Adding blocker ContentParent: id=1265a9f91580 for phase quit-application-granted
[task 2022-11-16T20:08:00.621Z] 20:08:00 INFO - DEBUG: Adding blocker places.sqlite#1: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2022-11-16T20:08:00.634Z] 20:08:00 INFO - DEBUG: Adding blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2022-11-16T20:08:00.644Z] 20:08:00 INFO - DEBUG: Adding blocker PlacesUtils wrapped connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2022-11-16T20:08:00.646Z] 20:08:00 INFO - DEBUG: Adding blocker PlacesUtils wrapped connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2022-11-16T20:08:00.672Z] 20:08:00 INFO - DEBUG: Adding blocker places.sqlite#1: PlacesExpiration.jsm: setup (0) for phase places.sqlite#1: waiting for clients
[task 2022-11-16T20:08:00.678Z] 20:08:00 INFO - DEBUG: Adding blocker places.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2022-11-16T20:08:00.680Z] 20:08:00 INFO - DEBUG: Adding blocker PlacesUtils read-only connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2022-11-16T20:08:00.683Z] 20:08:00 INFO - DEBUG: Adding blocker PlacesUtils read-only connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2022-11-16T20:08:01.073Z] 20:08:01 INFO - DEBUG: Completed blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-11-16T20:08:01.095Z] 20:08:01 INFO - DEBUG: Completed blocker places.sqlite#1: PlacesExpiration.jsm: setup (0) for phase places.sqlite#1: waiting for clients
[task 2022-11-16T20:08:01.432Z] 20:08:01 INFO - DEBUG: Adding blocker Search service: shutting down for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:08:01.836Z] 20:08:01 INFO - DEBUG: Adding blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2022-11-16T20:08:03.363Z] 20:08:03 INFO - DEBUG: Adding blocker Remote Settings profile-before-change for phase profile-before-change
[task 2022-11-16T20:08:03.979Z] 20:08:03 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:08:04.041Z] 20:08:04 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:08:04.085Z] 20:08:04 INFO - DEBUG: Adding blocker JSON store: writing data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-11-16T20:08:04.453Z] 20:08:04 INFO - 1668629284454 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2022-11-16T20:08:04.453Z] 20:08:04 INFO - DEBUG: Adding blocker ScriptPreloader: Saving bytecode cache for phase xpcom-will-shutdown
[task 2022-11-16T20:08:04.484Z] 20:08:04 INFO - 1668629284486 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=1600 waitForExplicitStart=false
[task 2022-11-16T20:08:04.490Z] 20:08:04 INFO - 1668629284488 RemoteAgent TRACE [3] ProgressListener Setting unload timer (1600ms)
[task 2022-11-16T20:08:04.491Z] 20:08:04 INFO - 1668629284489 RemoteAgent TRACE [3] Document already finished loading: about:blank
[task 2022-11-16T20:08:04.491Z] 20:08:04 INFO - 1668629284490 RemoteAgent TRACE [3] ProgressListener Stop: has error=false
[task 2022-11-16T20:08:04.525Z] 20:08:04 INFO - 1668629284527 Marionette DEBUG 2 <- [1,1,null,{"sessionId":"8f108d79-6fb0-4bb3-9ddf-8a63a3413439","capabilities":{"browserName":"firefox","browserVersion":"108.0","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20221116190415","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":6988,"moz:profile":"C:\\Users\\task_166862154791591\\AppData\\Local\\Temp\\tmpicscb86_.mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2022-11-16T20:08:04.566Z] 20:08:04 INFO - 1668629284564 Marionette DEBUG 2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2022-11-16T20:08:04.571Z] 20:08:04 INFO - 1668629284570 Marionette DEBUG 2 <- [1,2,null,{"value":null}]
[task 2022-11-16T20:08:04.579Z] 20:08:04 INFO - 1668629284578 Marionette DEBUG 2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2022-11-16T20:08:04.581Z] 20:08:04 INFO - 1668629284580 Marionette DEBUG 2 <- [1,3,null,{"value":null}]
[task 2022-11-16T20:08:04.590Z] 20:08:04 INFO - 1668629284589 Marionette DEBUG 2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2022-11-16T20:08:04.591Z] 20:08:04 INFO - 1668629284592 Marionette DEBUG 2 <- [1,4,null,{"value":null}]
[task 2022-11-16T20:08:04.603Z] 20:08:04 INFO - 1668629284602 Marionette DEBUG 2 -> [0,5,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:04.604Z] 20:08:04 INFO - 1668629284603 Marionette DEBUG 2 <- [1,5,null,{"value":"content"}]
[task 2022-11-16T20:08:04.607Z] 20:08:04 INFO - 1668629284607 Marionette DEBUG 2 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-11-16T20:08:04.608Z] 20:08:04 INFO - 1668629284608 Marionette DEBUG 2 <- [1,6,null,{"value":null}]
[task 2022-11-16T20:08:04.610Z] 20:08:04 INFO - 1668629284610 Marionette DEBUG 2 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2022-11-16T20:08:04.610Z] 20:08:04 INFO - 1668629284610 Marionette DEBUG 2 <- [1,7,null,{"value":"dbe9b5cd-016c-408d-9cb4-760487d0d809"}]
[task 2022-11-16T20:08:04.612Z] 20:08:04 INFO - 1668629284611 Marionette DEBUG 2 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.613Z] 20:08:04 INFO - 1668629284613 Marionette DEBUG 2 <- [1,8,null,{"value":null}]
[task 2022-11-16T20:08:04.615Z] 20:08:04 INFO - 1668629284614 Marionette DEBUG 2 -> [0,9,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:04.615Z] 20:08:04 INFO - 1668629284615 Marionette DEBUG 2 <- [1,9,null,{"value":"content"}]
[task 2022-11-16T20:08:04.616Z] 20:08:04 INFO - 1668629284616 Marionette DEBUG 2 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-11-16T20:08:04.617Z] 20:08:04 INFO - 1668629284617 Marionette DEBUG 2 <- [1,10,null,{"value":null}]
[task 2022-11-16T20:08:04.626Z] 20:08:04 INFO - 1668629284626 Marionette DEBUG 2 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:08:04.627Z] 20:08:04 INFO - 1668629284627 Marionette DEBUG 2 <- [1,11,null,["dbe9b5cd-016c-408d-9cb4-760487d0d809"]]
[task 2022-11-16T20:08:04.628Z] 20:08:04 INFO - 1668629284629 Marionette DEBUG 2 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.630Z] 20:08:04 INFO - 1668629284630 Marionette DEBUG 2 <- [1,12,null,{"value":null}]
[task 2022-11-16T20:08:04.631Z] 20:08:04 INFO - 1668629284632 Marionette DEBUG 2 -> [0,13,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:04.633Z] 20:08:04 INFO - 1668629284632 Marionette DEBUG 2 <- [1,13,null,{"value":"content"}]
[task 2022-11-16T20:08:04.636Z] 20:08:04 INFO - 1668629284636 Marionette DEBUG 2 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.638Z] 20:08:04 INFO - 1668629284637 Marionette DEBUG 2 <- [1,14,null,{"value":null}]
[task 2022-11-16T20:08:04.640Z] 20:08:04 INFO - 1668629284642 Marionette DEBUG 2 -> [0,15,"WebDriver:GetWindowHandle",{}]
[task 2022-11-16T20:08:04.644Z] 20:08:04 INFO - 1668629284644 Marionette DEBUG 2 <- [1,15,null,{"value":"6a966723-49e3-441a-8f4f-0006c83fab2b"}]
[task 2022-11-16T20:08:04.650Z] 20:08:04 INFO - 1668629284649 Marionette DEBUG 2 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.651Z] 20:08:04 INFO - 1668629284650 Marionette DEBUG 2 <- [1,16,null,{"value":null}]
[task 2022-11-16T20:08:04.652Z] 20:08:04 INFO - 1668629284653 Marionette DEBUG 2 -> [0,17,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:04.654Z] 20:08:04 INFO - 1668629284654 Marionette DEBUG 2 <- [1,17,null,{"value":"content"}]
[task 2022-11-16T20:08:04.655Z] 20:08:04 INFO - 1668629284656 Marionette DEBUG 2 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.655Z] 20:08:04 INFO - 1668629284656 Marionette DEBUG 2 <- [1,18,null,{"value":null}]
[task 2022-11-16T20:08:04.659Z] 20:08:04 INFO - 1668629284658 Marionette DEBUG 2 -> [0,19,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:08:04.660Z] 20:08:04 INFO - 1668629284660 Marionette DEBUG 2 <- [1,19,null,["6a966723-49e3-441a-8f4f-0006c83fab2b"]]
[task 2022-11-16T20:08:04.661Z] 20:08:04 INFO - 1668629284663 Marionette DEBUG 2 -> [0,20,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.664Z] 20:08:04 INFO - 1668629284663 Marionette DEBUG 2 <- [1,20,null,{"value":null}]
[task 2022-11-16T20:08:04.681Z] 20:08:04 INFO - 1668629284683 Marionette DEBUG 2 -> [0,21,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:04.685Z] 20:08:04 INFO - 1668629284684 Marionette DEBUG 2 <- [1,21,null,{"value":"content"}]
[task 2022-11-16T20:08:04.687Z] 20:08:04 INFO - 1668629284687 Marionette DEBUG 2 -> [0,22,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.687Z] 20:08:04 INFO - 1668629284687 Marionette DEBUG 2 <- [1,22,null,{"value":null}]
[task 2022-11-16T20:08:04.690Z] 20:08:04 INFO - 1668629284689 Marionette DEBUG 2 -> [0,23,"WebDriver:GetWindowHandles",{}]
[task 2022-11-16T20:08:04.692Z] 20:08:04 INFO - 1668629284691 Marionette DEBUG 2 <- [1,23,null,["6a966723-49e3-441a-8f4f-0006c83fab2b"]]
[task 2022-11-16T20:08:04.694Z] 20:08:04 INFO - 1668629284694 Marionette DEBUG 2 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:04.694Z] 20:08:04 INFO - 1668629284694 Marionette DEBUG 2 <- [1,24,null,{"value":null}]
[task 2022-11-16T20:08:04.698Z] 20:08:04 INFO - 1668629284697 Marionette DEBUG 2 -> [0,25,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2022-11-16T20:08:04.782Z] 20:08:04 INFO - 1668629284778 RemoteAgent TRACE Received DOM event TabOpen for [object XULElement]
[task 2022-11-16T20:08:05.103Z] 20:08:05 INFO - 1668629285104 RemoteAgent TRACE [12] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=1600 waitForExplicitStart=false
[task 2022-11-16T20:08:05.103Z] 20:08:05 INFO - 1668629285105 RemoteAgent TRACE [12] ProgressListener Setting unload timer (1600ms)
[task 2022-11-16T20:08:05.205Z] 20:08:05 INFO - 1668629285203 RemoteAgent TRACE [12] ProgressListener Check loading state: isStart=1 isStop=0
[task 2022-11-16T20:08:05.205Z] 20:08:05 INFO - 1668629285203 RemoteAgent TRACE [12] ProgressListener state=start: about:blank
[task 2022-11-16T20:08:05.206Z] 20:08:05 INFO - 1668629285203 RemoteAgent TRACE [12] ProgressListener Cleared the unload timer
[task 2022-11-16T20:08:05.216Z] 20:08:05 INFO - 1668629285214 RemoteAgent TRACE [12] ProgressListener Check loading state: isStart=0 isStop=16
[task 2022-11-16T20:08:05.216Z] 20:08:05 INFO - 1668629285215 RemoteAgent TRACE [12] ProgressListener Ignore aborted navigation error to the initial document, real document will be loaded.
[task 2022-11-16T20:08:05.218Z] 20:08:05 INFO - 1668629285217 RemoteAgent TRACE [12] ProgressListener Check loading state: isStart=1 isStop=0
[task 2022-11-16T20:08:05.622Z] 20:08:05 INFO - 1668629285619 RemoteAgent TRACE [12] ProgressListener Check loading state: isStart=0 isStop=16
[task 2022-11-16T20:08:05.631Z] 20:08:05 INFO - 1668629285621 RemoteAgent TRACE [12] ProgressListener state=stop: about:blank
[task 2022-11-16T20:08:05.631Z] 20:08:05 INFO - 1668629285622 RemoteAgent TRACE [12] ProgressListener Stop: has error=false
[task 2022-11-16T20:08:05.631Z] 20:08:05 INFO - 1668629285626 Marionette DEBUG 2 <- [1,25,null,{"handle":"2aa8963a-e6fc-4527-8dd5-cdd642d8f037","type":"tab"}]
[task 2022-11-16T20:08:05.664Z] 20:08:05 INFO - 1668629285664 Marionette DEBUG 2 -> [0,26,"Marionette:GetContext",{}]
[task 2022-11-16T20:08:05.670Z] 20:08:05 INFO - 1668629285667 Marionette DEBUG 2 <- [1,26,null,{"value":"content"}]
[task 2022-11-16T20:08:05.679Z] 20:08:05 INFO - 1668629285676 Marionette DEBUG 2 -> [0,27,"Marionette:SetContext",{"value":"content"}]
[task 2022-11-16T20:08:05.680Z] 20:08:05 INFO - 1668629285678 Marionette DEBUG 2 <- [1,27,null,{"value":null}]
[task 2022-11-16T20:08:05.684Z] 20:08:05 INFO - 1668629285683 Marionette DEBUG 2 -> [0,28,"WebDriver:GetWindowHandles",{}]
|
||
Updated•2 years ago
|
|
||
Updated•2 years ago
|
Product: Testing → Remote Protocol
|
|
||
Comment 2•2 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in
before you can comment on or make changes to this bug.
Description
•