Closed Bug 1819734 Opened 2 years ago Closed 2 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/send_alert_text/send.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1630162

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=407457202&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZxfVJn5XQXqC3mO_zahQxQ/runs/0/artifacts/public/logs/live_backing.log


[task 2023-03-01T19:43:49.544Z] 19:43:49     INFO - STDOUT: PASSED
[task 2023-03-01T19:43:49.544Z] 19:43:49     INFO - PID 14047 | 1677699829538	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:49.544Z] 19:43:49     INFO - PID 14047 | 1677699829540	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/alert/dismiss {}
[task 2023-03-01T19:43:49.553Z] 19:43:49     INFO - PID 14047 | 1677699829552	Marionette	DEBUG	0 -> [0,469,"WebDriver:DismissAlert",{}]
[task 2023-03-01T19:43:49.645Z] 19:43:49     INFO - PID 14047 | 1677699829644	Marionette	TRACE	Received event DOMModalDialogClosed
[task 2023-03-01T19:43:49.656Z] 19:43:49     INFO - PID 14047 | 1677699829655	Marionette	DEBUG	0 <- [1,469,null,{"value":null}]
[task 2023-03-01T19:43:49.663Z] 19:43:49     INFO - PID 14047 | 1677699829662	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:49.664Z] 19:43:49     INFO - PID 14047 | 1677699829663	webdriver::server	DEBUG	-> DELETE /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window
[task 2023-03-01T19:43:49.689Z] 19:43:49     INFO - PID 14047 | 1677699829688	Marionette	DEBUG	0 -> [0,470,"WebDriver:CloseWindow",{}]
[task 2023-03-01T19:43:49.710Z] 19:43:49     INFO - PID 14047 | 1677699829709	RemoteAgent	TRACE	Received DOM event TabClose for [object XULElement]
[task 2023-03-01T19:43:49.744Z] 19:43:49     INFO - PID 14047 | 1677699829742	Marionette	TRACE	[119] MarionetteCommands actor destroyed for window id 85899345921
[task 2023-03-01T19:43:49.834Z] 19:43:49     INFO - PID 14047 | 1677699829833	Marionette	TRACE	Received observer notification message-manager-disconnect
[task 2023-03-01T19:43:49.835Z] 19:43:49     INFO - PID 14047 | 1677699829834	Marionette	DEBUG	0 <- [1,470,null,["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]]
[task 2023-03-01T19:43:49.872Z] 19:43:49     INFO - PID 14047 | 1677699829871	webdriver::server	DEBUG	<- 200 OK {"value":["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]}
[task 2023-03-01T19:43:49.874Z] 19:43:49     INFO - PID 14047 | 1677699829872	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window {"handle": "a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:49.904Z] 19:43:49     INFO - PID 14047 | 1677699829903	Marionette	DEBUG	0 -> [0,471,"WebDriver:SwitchToWindow",{"handle":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:49.906Z] 19:43:49     INFO - PID 14047 | 1677699829905	Marionette	DEBUG	0 <- [1,471,null,{"value":null}]
[task 2023-03-01T19:43:49.910Z] 19:43:49     INFO - PID 14047 | 1677699829909	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:49.912Z] 19:43:49     INFO - PID 14047 | 1677699829911	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/timeouts {"implicit": 0}
[task 2023-03-01T19:43:49.977Z] 19:43:49     INFO - PID 14047 | 1677699829976	Marionette	DEBUG	0 -> [0,472,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-03-01T19:43:49.978Z] 19:43:49     INFO - PID 14047 | 1677699829977	Marionette	DEBUG	0 <- [1,472,null,{"value":null}]
[task 2023-03-01T19:43:49.988Z] 19:43:49     INFO - PID 14047 | 1677699829987	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:49.990Z] 19:43:49     INFO - PID 14047 | 1677699829989	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/timeouts {"pageLoad": 300000}
[task 2023-03-01T19:43:50.010Z] 19:43:50     INFO - PID 14047 | 1677699830009	Marionette	DEBUG	0 -> [0,473,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-03-01T19:43:50.011Z] 19:43:50     INFO - PID 14047 | 1677699830011	Marionette	DEBUG	0 <- [1,473,null,{"value":null}]
[task 2023-03-01T19:43:50.045Z] 19:43:50     INFO - PID 14047 | 1677699830044	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.047Z] 19:43:50     INFO - PID 14047 | 1677699830046	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/timeouts {"script": 30000}
[task 2023-03-01T19:43:50.085Z] 19:43:50     INFO - PID 14047 | 1677699830084	Marionette	DEBUG	0 -> [0,474,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-03-01T19:43:50.087Z] 19:43:50     INFO - PID 14047 | 1677699830085	Marionette	DEBUG	0 <- [1,474,null,{"value":null}]
[task 2023-03-01T19:43:50.088Z] 19:43:50     INFO - PID 14047 | 1677699830087	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.089Z] 19:43:50     INFO - PID 14047 | 1677699830089	webdriver::server	DEBUG	-> GET /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window
[task 2023-03-01T19:43:50.133Z] 19:43:50     INFO - PID 14047 | 1677699830132	Marionette	DEBUG	0 -> [0,475,"WebDriver:GetWindowHandle",{}]
[task 2023-03-01T19:43:50.136Z] 19:43:50     INFO - PID 14047 | 1677699830133	Marionette	DEBUG	0 <- [1,475,null,{"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.170Z] 19:43:50     INFO - PID 14047 | 1677699830169	webdriver::server	DEBUG	<- 200 OK {"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.171Z] 19:43:50     INFO - PID 14047 | 1677699830170	webdriver::server	DEBUG	-> GET /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window
[task 2023-03-01T19:43:50.181Z] 19:43:50     INFO - PID 14047 | 1677699830180	Marionette	DEBUG	0 -> [0,476,"WebDriver:GetWindowHandle",{}]
[task 2023-03-01T19:43:50.181Z] 19:43:50     INFO - PID 14047 | 1677699830180	Marionette	DEBUG	0 <- [1,476,null,{"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.185Z] 19:43:50     INFO - PID 14047 | 1677699830184	webdriver::server	DEBUG	<- 200 OK {"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.186Z] 19:43:50     INFO - PID 14047 | 1677699830185	webdriver::server	DEBUG	-> GET /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window/handles
[task 2023-03-01T19:43:50.377Z] 19:43:50     INFO - PID 14047 | 1677699830376	Marionette	DEBUG	0 -> [0,477,"WebDriver:GetWindowHandles",{}]
[task 2023-03-01T19:43:50.378Z] 19:43:50     INFO - PID 14047 | 1677699830377	Marionette	DEBUG	0 <- [1,477,null,["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]]
[task 2023-03-01T19:43:50.404Z] 19:43:50     INFO - PID 14047 | 1677699830403	webdriver::server	DEBUG	<- 200 OK {"value":["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]}
[task 2023-03-01T19:43:50.406Z] 19:43:50     INFO - PID 14047 | 1677699830404	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window {"handle": "a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.411Z] 19:43:50     INFO - PID 14047 | 1677699830410	Marionette	DEBUG	0 -> [0,478,"WebDriver:SwitchToWindow",{"handle":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.412Z] 19:43:50     INFO - PID 14047 | 1677699830412	Marionette	DEBUG	0 <- [1,478,null,{"value":null}]
[task 2023-03-01T19:43:50.453Z] 19:43:50     INFO - PID 14047 | 1677699830452	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.455Z] 19:43:50     INFO - PID 14047 | 1677699830454	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/alert/dismiss {}
[task 2023-03-01T19:43:50.493Z] 19:43:50     INFO - PID 14047 | 1677699830492	Marionette	DEBUG	0 -> [0,479,"WebDriver:DismissAlert",{}]
[task 2023-03-01T19:43:50.496Z] 19:43:50     INFO - PID 14047 | 1677699830494	Marionette	DEBUG	0 <- [1,479,{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8\nWebDriverError@chrome://remote/content/shared/webdriver/Er ... ote/content/marionette/server.sys.mjs:250:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"},null]
[task 2023-03-01T19:43:50.498Z] 19:43:50     INFO - PID 14047 | 1677699830496	webdriver::server	DEBUG	<- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/Remo ... ontent/marionette/server.sys.mjs:250:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"}}
[task 2023-03-01T19:43:50.500Z] 19:43:50     INFO - PID 14047 | 1677699830498	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window {"handle": "a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.544Z] 19:43:50     INFO - PID 14047 | 1677699830543	Marionette	DEBUG	0 -> [0,480,"WebDriver:SwitchToWindow",{"handle":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.547Z] 19:43:50     INFO - PID 14047 | 1677699830547	Marionette	DEBUG	0 <- [1,480,null,{"value":null}]
[task 2023-03-01T19:43:50.582Z] 19:43:50     INFO - PID 14047 | 1677699830582	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.584Z] 19:43:50     INFO - PID 14047 | 1677699830582	webdriver::server	DEBUG	-> GET /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window
[task 2023-03-01T19:43:50.591Z] 19:43:50     INFO - PID 14047 | 1677699830590	Marionette	DEBUG	0 -> [0,481,"WebDriver:GetWindowHandle",{}]
[task 2023-03-01T19:43:50.591Z] 19:43:50     INFO - PID 14047 | 1677699830590	Marionette	DEBUG	0 <- [1,481,null,{"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.599Z] 19:43:50     INFO - PID 14047 | 1677699830598	webdriver::server	DEBUG	<- 200 OK {"value":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.600Z] 19:43:50     INFO - PID 14047 | 1677699830599	webdriver::server	DEBUG	-> GET /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window/handles
[task 2023-03-01T19:43:50.663Z] 19:43:50     INFO - PID 14047 | 1677699830662	Marionette	DEBUG	0 -> [0,482,"WebDriver:GetWindowHandles",{}]
[task 2023-03-01T19:43:50.664Z] 19:43:50     INFO - PID 14047 | 1677699830663	Marionette	DEBUG	0 <- [1,482,null,["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]]
[task 2023-03-01T19:43:50.698Z] 19:43:50     INFO - PID 14047 | 1677699830697	webdriver::server	DEBUG	<- 200 OK {"value":["a78a2db3-93bc-49c2-9761-ea32827e8e5d"]}
[task 2023-03-01T19:43:50.699Z] 19:43:50     INFO - PID 14047 | 1677699830698	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window {"handle": "a78a2db3-93bc-49c2-9761-ea32827e8e5d"}
[task 2023-03-01T19:43:50.709Z] 19:43:50     INFO - PID 14047 | 1677699830708	Marionette	DEBUG	0 -> [0,483,"WebDriver:SwitchToWindow",{"handle":"a78a2db3-93bc-49c2-9761-ea32827e8e5d"}]
[task 2023-03-01T19:43:50.711Z] 19:43:50     INFO - PID 14047 | 1677699830710	Marionette	DEBUG	0 <- [1,483,null,{"value":null}]
[task 2023-03-01T19:43:50.746Z] 19:43:50     INFO - PID 14047 | 1677699830746	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.748Z] 19:43:50     INFO - PID 14047 | 1677699830747	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/window/rect {"width": 800, "height": 600}
[task 2023-03-01T19:43:50.790Z] 19:43:50     INFO - PID 14047 | 1677699830789	Marionette	DEBUG	0 -> [0,484,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2023-03-01T19:43:50.791Z] 19:43:50     INFO - PID 14047 | 1677699830790	Marionette	TRACE	Requested window geometry matches
[task 2023-03-01T19:43:50.793Z] 19:43:50     INFO - PID 14047 | 1677699830792	Marionette	DEBUG	0 <- [1,484,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2023-03-01T19:43:50.795Z] 19:43:50     INFO - PID 14047 | 1677699830794	webdriver::server	DEBUG	<- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2023-03-01T19:43:50.796Z] 19:43:50     INFO - PID 14047 | 1677699830795	webdriver::server	DEBUG	-> POST /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1/frame {"id": null}
[task 2023-03-01T19:43:50.842Z] 19:43:50     INFO - PID 14047 | 1677699830841	Marionette	DEBUG	0 -> [0,485,"WebDriver:SwitchToFrame",{"id":null}]
[task 2023-03-01T19:43:50.879Z] 19:43:50     INFO - PID 14047 | 1677699830878	Marionette	DEBUG	0 <- [1,485,null,{"value":null}]
[task 2023-03-01T19:43:50.891Z] 19:43:50     INFO - PID 14047 | 1677699830890	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-03-01T19:43:50.896Z] 19:43:50     INFO - PID 14047 | 1677699830895	webdriver::server	DEBUG	-> DELETE /session/a5529356-b5fb-4d4c-b5df-cd98b6a73bb1
[task 2023-03-01T19:43:50.960Z] 19:43:50     INFO - PID 14047 | 1677699830959	Marionette	DEBUG	0 -> [0,486,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2023-03-01T19:43:50.961Z] 19:43:50     INFO - PID 14047 | 1677699830960	Marionette	INFO	Stopped listening on port 42417
[task 2023-03-01T19:43:50.965Z] 19:43:50     INFO - PID 14047 | 1677699830963	Marionette	TRACE	[3] MarionetteCommands actor destroyed for window id 4294967297
[task 2023-03-01T19:43:51.296Z] 19:43:51     INFO - PID 14047 | 1677699831295	Marionette	TRACE	Received observer notification quit-application
[task 2023-03-01T19:43:51.303Z] 19:43:51     INFO - PID 14047 | 1677699831302	Marionette	TRACE	Received observer notification quit-application
[task 2023-03-01T19:43:51.306Z] 19:43:51     INFO - PID 14047 | 1677699831305	Marionette	DEBUG	Marionette stopped listening
[task 2023-03-01T19:43:51.312Z] 19:43:51     INFO - PID 14047 | 1677699831311	Marionette	DEBUG	0 <- [1,486,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2023-03-01T19:43:51.499Z] 19:43:51     INFO - PID 14047 | 1677699831498	webdriver::server	DEBUG	Teardown session
[task 2023-03-01T19:43:51.523Z] 19:43:51     INFO - PID 14047 | 1677699831522	Marionette	DEBUG	Closed connection 0
[task 2023-03-01T19:44:03.333Z] 19:44:03     INFO - PID 14047 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 237))
[task 2023-03-01T19:44:03.334Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://services-settings/Utils.jsm, line 237: TypeError: NetworkError: Network request failed
[task 2023-03-01T19:44:03.644Z] 19:44:03     INFO - PID 14047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:44:03.645Z] 19:44:03     INFO - PID 14047 |           Blocker:  Waiting for ping task
[task 2023-03-01T19:44:03.646Z] 19:44:03     INFO - PID 14047 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:44:03.646Z] 19:44:03     INFO - PID 14047 |           State: (none)
[task 2023-03-01T19:44:03.647Z] 19:44:03     INFO - PID 14047 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.647Z] 19:44:03     INFO - PID 14047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:44:03.648Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:44:03.649Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:44:03.649Z] 19:44:03     INFO - PID 14047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:44:03.650Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:44:03.650Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:44:03.651Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:44:03.651Z] 19:44:03     INFO - PID 14047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:44:03.652Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:44:03.652Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:44:03.653Z] 19:44:03     INFO - PID 14047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-03-01T19:44:03.653Z] 19:44:03     INFO - PID 14047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:44:03.668Z] 19:44:03     INFO - PID 14047 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-01T19:44:03.755Z] 19:44:03     INFO - PID 14047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:44:03.756Z] 19:44:03     INFO - PID 14047 |           Blocker:  Waiting for ping task
[task 2023-03-01T19:44:03.757Z] 19:44:03     INFO - PID 14047 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:44:03.757Z] 19:44:03     INFO - PID 14047 |           State: (none)
[task 2023-03-01T19:44:03.760Z] 19:44:03     INFO - PID 14047 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.760Z] 19:44:03     INFO - PID 14047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:44:03.761Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:44:03.761Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:44:03.761Z] 19:44:03     INFO - PID 14047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:44:03.761Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:44:03.762Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:44:03.762Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:44:03.763Z] 19:44:03     INFO - PID 14047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:44:03.763Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:44:03.764Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:44:03.764Z] 19:44:03     INFO - PID 14047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-03-01T19:44:03.765Z] 19:44:03     INFO - PID 14047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:44:03.765Z] 19:44:03     INFO - PID 14047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:44:03.765Z] 19:44:03     INFO - PID 14047 |           Blocker:  TelemetryController: shutting down
[task 2023-03-01T19:44:03.766Z] 19:44:03     INFO - PID 14047 |           Phase: profile-before-change-telemetry
[task 2023-03-01T19:44:03.766Z] 19:44:03     INFO - PID 14047 |           State: Error getting state: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange" at addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:44:03.767Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:44:03.767Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:44:03.767Z] 19:44:03     INFO - PID 14047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:44:03.768Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:44:03.768Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:44:03.768Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:44:03.769Z] 19:44:03     INFO - PID 14047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:44:03.769Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:44:03.770Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:44:03.770Z] 19:44:03     INFO - PID 14047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-03-01T19:44:03.771Z] 19:44:03     INFO - PID 14047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:44:03.771Z] 19:44:03     INFO - PID 14047 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.772Z] 19:44:03     INFO - PID 14047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:44:03.772Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:44:03.773Z] 19:44:03     INFO - PID 14047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:44:03.773Z] 19:44:03     INFO - PID 14047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:44:03.773Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:44:03.774Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:44:03.774Z] 19:44:03     INFO - PID 14047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:44:03.775Z] 19:44:03     INFO - PID 14047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:44:03.775Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:44:03.775Z] 19:44:03     INFO - PID 14047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:44:03.776Z] 19:44:03     INFO - PID 14047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-03-01T19:44:03.776Z] 19:44:03     INFO - PID 14047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:44:03.780Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.781Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.782Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.783Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:03.783Z] 19:44:03     INFO - PID 14047 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:44:06.976Z] 19:44:06     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/send_alert_text/send.py | expected OK
[task 2023-03-01T19:44:06.976Z] 19:44:06     INFO - TEST-INFO took 80004ms
[task 2023-03-01T19:44:06.979Z] 19:44:06     INFO - Restarting browser for new test group
[task 2023-03-01T19:44:07.062Z] 19:44:07     INFO - Closing logging queue
[task 2023-03-01T19:44:07.063Z] 19:44:07     INFO - queue closed
[task 2023-03-01T19:44:07.073Z] 19:44:07     INFO - PID 15148 | 1677699847072	geckodriver	INFO	Listening on 127.0.0.1:49215
[task 2023-03-01T19:44:07.074Z] 19:44:07     INFO - Starting runner
[task 2023-03-01T19:44:07.315Z] 19:44:07     INFO - TEST-START | /webdriver/tests/take_screenshot/iframe.py
Status: NEW → RESOLVED
Closed: 2 years ago
Duplicate of bug: 1630162
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.