1875706 - Intermittent webdriver/tests/bidi/network/response_started/response_started.py | single tracking bug

Status: REOPENED

(Remote Protocol :: WebDriver BiDi, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=444064970&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/bH_BsuYMQLaxKmnlY_-Mdw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2024-01-21T15:40:54.789Z] 15:40:54     INFO - STDOUT: PASSED
[task 2024-01-21T15:40:54.790Z] 15:40:54     INFO - PID 7500 | 1705851654788	RemoteAgent	DEBUG	WebDriverBiDiConnection 88ef7d1b-0358-4c85-a624-e69e111aedc4 -> {"id":325,"method":"session.unsubscribe","params":{"events":["network.responseStarted"]}}
[task 2024-01-21T15:40:54.791Z] 15:40:54     INFO - PID 7500 | 1705851654789	RemoteAgent	TRACE	Module root/session.sys.mjs found for ROOT
[task 2024-01-21T15:40:54.792Z] 15:40:54     INFO - PID 7500 | 1705851654789	RemoteAgent	TRACE	Received command session.unsubscribe for destination ROOT
[task 2024-01-21T15:40:54.793Z] 15:40:54     INFO - PID 7500 | 1705851654789	RemoteAgent	TRACE	Module root/session.sys.mjs found for ROOT
[task 2024-01-21T15:40:54.793Z] 15:40:54     INFO - PID 7500 | 1705851654789	RemoteAgent	TRACE	Module root/network.sys.mjs found for ROOT
[task 2024-01-21T15:40:54.794Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	TRACE	Module windowglobal-in-root/network.sys.mjs not found for WINDOW_GLOBAL
[task 2024-01-21T15:40:54.795Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	TRACE	Module windowglobal/network.sys.mjs not found for WINDOW_GLOBAL
[task 2024-01-21T15:40:54.796Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	TRACE	Module root/network.sys.mjs found for ROOT
[task 2024-01-21T15:40:54.796Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	TRACE	Received command network._applySessionData for destination ROOT
[task 2024-01-21T15:40:54.797Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	TRACE	Module root/network.sys.mjs found for ROOT
[task 2024-01-21T15:40:54.798Z] 15:40:54     INFO - PID 7500 | 1705851654791	RemoteAgent	DEBUG	WebDriverBiDiConnection 88ef7d1b-0358-4c85-a624-e69e111aedc4 <- {"type":"success","id":325,"result":{}}
[task 2024-01-21T15:40:54.798Z] 15:40:54     INFO - PID 7500 | 1705851654793	RemoteAgent	DEBUG	WebDriverBiDiConnection 88ef7d1b-0358-4c85-a624-e69e111aedc4 closed
[task 2024-01-21T15:40:54.800Z] 15:40:54     INFO - PID 7500 | 1705851654794	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/timeouts {"implicit": 0}
[task 2024-01-21T15:40:54.800Z] 15:40:54     INFO - PID 7500 | 1705851654795	Marionette	DEBUG	0 -> [0,724,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2024-01-21T15:40:54.801Z] 15:40:54     INFO - PID 7500 | 1705851654796	Marionette	DEBUG	0 <- [1,724,null,{"value":null}]
[task 2024-01-21T15:40:54.801Z] 15:40:54     INFO - PID 7500 | 1705851654796	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.802Z] 15:40:54     INFO - PID 7500 | 1705851654797	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/timeouts {"pageLoad": 300000}
[task 2024-01-21T15:40:54.803Z] 15:40:54     INFO - PID 7500 | 1705851654798	Marionette	DEBUG	0 -> [0,725,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2024-01-21T15:40:54.803Z] 15:40:54     INFO - PID 7500 | 1705851654798	Marionette	DEBUG	0 <- [1,725,null,{"value":null}]
[task 2024-01-21T15:40:54.804Z] 15:40:54     INFO - PID 7500 | 1705851654799	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.805Z] 15:40:54     INFO - PID 7500 | 1705851654800	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/timeouts {"script": 30000}
[task 2024-01-21T15:40:54.806Z] 15:40:54     INFO - PID 7500 | 1705851654800	Marionette	DEBUG	0 -> [0,726,"WebDriver:SetTimeouts",{"script":30000}]
[task 2024-01-21T15:40:54.807Z] 15:40:54     INFO - PID 7500 | 1705851654801	Marionette	DEBUG	0 <- [1,726,null,{"value":null}]
[task 2024-01-21T15:40:54.808Z] 15:40:54     INFO - PID 7500 | 1705851654801	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.808Z] 15:40:54     INFO - PID 7500 | 1705851654802	webdriver::server	DEBUG	-> GET /session/31416ead-c554-456a-ab23-073bf9585e9b/window
[task 2024-01-21T15:40:54.809Z] 15:40:54     INFO - PID 7500 | 1705851654803	Marionette	DEBUG	0 -> [0,727,"WebDriver:GetWindowHandle",{}]
[task 2024-01-21T15:40:54.810Z] 15:40:54     INFO - PID 7500 | 1705851654803	Marionette	DEBUG	0 <- [1,727,null,{"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.811Z] 15:40:54     INFO - PID 7500 | 1705851654804	webdriver::server	DEBUG	<- 200 OK {"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.812Z] 15:40:54     INFO - PID 7500 | 1705851654804	webdriver::server	DEBUG	-> GET /session/31416ead-c554-456a-ab23-073bf9585e9b/window
[task 2024-01-21T15:40:54.812Z] 15:40:54     INFO - PID 7500 | 1705851654805	Marionette	DEBUG	0 -> [0,728,"WebDriver:GetWindowHandle",{}]
[task 2024-01-21T15:40:54.813Z] 15:40:54     INFO - PID 7500 | 1705851654806	Marionette	DEBUG	0 <- [1,728,null,{"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.813Z] 15:40:54     INFO - PID 7500 | 1705851654806	webdriver::server	DEBUG	<- 200 OK {"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.815Z] 15:40:54     INFO - PID 7500 | 1705851654807	webdriver::server	DEBUG	-> GET /session/31416ead-c554-456a-ab23-073bf9585e9b/window/handles
[task 2024-01-21T15:40:54.815Z] 15:40:54     INFO - PID 7500 | 1705851654808	Marionette	DEBUG	0 -> [0,729,"WebDriver:GetWindowHandles",{}]
[task 2024-01-21T15:40:54.816Z] 15:40:54     INFO - PID 7500 | 1705851654808	Marionette	DEBUG	0 <- [1,729,null,["cb96bf32-3f08-49f4-87bc-f4bb0557d072"]]
[task 2024-01-21T15:40:54.817Z] 15:40:54     INFO - PID 7500 | 1705851654809	webdriver::server	DEBUG	<- 200 OK {"value":["cb96bf32-3f08-49f4-87bc-f4bb0557d072"]}
[task 2024-01-21T15:40:54.817Z] 15:40:54     INFO - PID 7500 | 1705851654809	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/window {"handle": "cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.818Z] 15:40:54     INFO - PID 7500 | 1705851654810	Marionette	DEBUG	0 -> [0,730,"WebDriver:SwitchToWindow",{"handle":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.819Z] 15:40:54     INFO - PID 7500 | 1705851654811	Marionette	DEBUG	0 <- [1,730,null,{"value":null}]
[task 2024-01-21T15:40:54.819Z] 15:40:54     INFO - PID 7500 | 1705851654811	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.820Z] 15:40:54     INFO - PID 7500 | 1705851654812	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/alert/dismiss {}
[task 2024-01-21T15:40:54.821Z] 15:40:54     INFO - PID 7500 | 1705851654813	Marionette	DEBUG	0 -> [0,731,"WebDriver:DismissAlert",{}]
[task 2024-01-21T15:40:54.822Z] 15:40:54     INFO - PID 7500 | 1705851654813	Marionette	DEBUG	0 <- [1,731,{"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:263:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:494:20\n"},null]
[task 2024-01-21T15:40:54.823Z] 15:40:54     INFO - PID 7500 | 1705851654814	webdriver::server	DEBUG	<- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/Remo ... ontent/marionette/server.sys.mjs:263:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:494:20\n"}}
[task 2024-01-21T15:40:54.824Z] 15:40:54     INFO - PID 7500 | 1705851654814	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/window {"handle": "cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.825Z] 15:40:54     INFO - PID 7500 | 1705851654815	Marionette	DEBUG	0 -> [0,732,"WebDriver:SwitchToWindow",{"handle":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.826Z] 15:40:54     INFO - PID 7500 | 1705851654816	Marionette	DEBUG	0 <- [1,732,null,{"value":null}]
[task 2024-01-21T15:40:54.826Z] 15:40:54     INFO - PID 7500 | 1705851654816	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.827Z] 15:40:54     INFO - PID 7500 | 1705851654817	webdriver::server	DEBUG	-> GET /session/31416ead-c554-456a-ab23-073bf9585e9b/window
[task 2024-01-21T15:40:54.827Z] 15:40:54     INFO - PID 7500 | 1705851654817	Marionette	DEBUG	0 -> [0,733,"WebDriver:GetWindowHandle",{}]
[task 2024-01-21T15:40:54.828Z] 15:40:54     INFO - PID 7500 | 1705851654818	Marionette	DEBUG	0 <- [1,733,null,{"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.829Z] 15:40:54     INFO - PID 7500 | 1705851654818	webdriver::server	DEBUG	<- 200 OK {"value":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.829Z] 15:40:54     INFO - PID 7500 | 1705851654819	webdriver::server	DEBUG	-> GET /session/31416ead-c554-456a-ab23-073bf9585e9b/window/handles
[task 2024-01-21T15:40:54.831Z] 15:40:54     INFO - PID 7500 | 1705851654819	Marionette	DEBUG	0 -> [0,734,"WebDriver:GetWindowHandles",{}]
[task 2024-01-21T15:40:54.831Z] 15:40:54     INFO - PID 7500 | 1705851654820	Marionette	DEBUG	0 <- [1,734,null,["cb96bf32-3f08-49f4-87bc-f4bb0557d072"]]
[task 2024-01-21T15:40:54.832Z] 15:40:54     INFO - PID 7500 | 1705851654820	webdriver::server	DEBUG	<- 200 OK {"value":["cb96bf32-3f08-49f4-87bc-f4bb0557d072"]}
[task 2024-01-21T15:40:54.833Z] 15:40:54     INFO - PID 7500 | 1705851654821	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/window {"handle": "cb96bf32-3f08-49f4-87bc-f4bb0557d072"}
[task 2024-01-21T15:40:54.834Z] 15:40:54     INFO - PID 7500 | 1705851654822	Marionette	DEBUG	0 -> [0,735,"WebDriver:SwitchToWindow",{"handle":"cb96bf32-3f08-49f4-87bc-f4bb0557d072"}]
[task 2024-01-21T15:40:54.834Z] 15:40:54     INFO - PID 7500 | 1705851654822	Marionette	DEBUG	0 <- [1,735,null,{"value":null}]
[task 2024-01-21T15:40:54.835Z] 15:40:54     INFO - PID 7500 | 1705851654823	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.836Z] 15:40:54     INFO - PID 7500 | 1705851654823	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/window/rect {"width": 800, "height": 600}
[task 2024-01-21T15:40:54.836Z] 15:40:54     INFO - PID 7500 | 1705851654824	Marionette	DEBUG	0 -> [0,736,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2024-01-21T15:40:54.837Z] 15:40:54     INFO - PID 7500 | 1705851654824	Marionette	TRACE	Requested window geometry matches
[task 2024-01-21T15:40:54.837Z] 15:40:54     INFO - PID 7500 | 1705851654824	Marionette	DEBUG	0 <- [1,736,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2024-01-21T15:40:54.838Z] 15:40:54     INFO - PID 7500 | 1705851654825	webdriver::server	DEBUG	<- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2024-01-21T15:40:54.839Z] 15:40:54     INFO - PID 7500 | 1705851654825	webdriver::server	DEBUG	-> POST /session/31416ead-c554-456a-ab23-073bf9585e9b/frame {"id": null}
[task 2024-01-21T15:40:54.839Z] 15:40:54     INFO - PID 7500 | 1705851654826	Marionette	DEBUG	0 -> [0,737,"WebDriver:SwitchToFrame",{"id":null}]
[task 2024-01-21T15:40:54.840Z] 15:40:54     INFO - PID 7500 | 1705851654827	Marionette	TRACE	[13] MarionetteCommands actor created for window id 8589934642
[task 2024-01-21T15:40:54.841Z] 15:40:54     INFO - PID 7500 | 1705851654828	Marionette	DEBUG	0 <- [1,737,null,{"value":null}]
[task 2024-01-21T15:40:54.841Z] 15:40:54     INFO - PID 7500 | 1705851654828	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2024-01-21T15:40:54.842Z] 15:40:54     INFO - PID 7500 | 1705851654836	webdriver::server	DEBUG	-> DELETE /session/31416ead-c554-456a-ab23-073bf9585e9b
[task 2024-01-21T15:40:54.843Z] 15:40:54     INFO - PID 7500 | 1705851654836	Marionette	DEBUG	0 -> [0,738,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2024-01-21T15:40:54.843Z] 15:40:54     INFO - PID 7500 | 1705851654838	Marionette	INFO	Stopped listening on port 57618
[task 2024-01-21T15:40:54.853Z] 15:40:54     INFO - PID 7500 | 1705851654852	Marionette	TRACE	[12] MarionetteCommands actor destroyed for window id 8589934595
[task 2024-01-21T15:40:54.854Z] 15:40:54     INFO - PID 7500 | 1705851654852	Marionette	TRACE	[13] MarionetteCommands actor destroyed for window id 8589934642
[task 2024-01-21T15:40:54.855Z] 15:40:54     INFO - PID 7500 | 1705851654854	WebDriver BiDi	DEBUG	Unregistered session handler: /session/31416ead-c554-456a-ab23-073bf9585e9b
[task 2024-01-21T15:40:54.859Z] 15:40:54     INFO - PID 7500 | 1705851654858	RemoteAgent	TRACE	MessageHandler ROOT for session 31416ead-c554-456a-ab23-073bf9585e9b is being destroyed
[task 2024-01-21T15:40:54.859Z] 15:40:54     INFO - PID 7500 | 1705851654859	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session 31416ead-c554-456a-ab23-073bf9585e9b
[task 2024-01-21T15:40:54.892Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.894Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.902Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.903Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.904Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.906Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.908Z] 15:40:54     INFO - PID 7500 | [Child 6880, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-01-21T15:40:54.947Z] 15:40:54     INFO - PID 7500 | 1705851654946	Marionette	TRACE	Received observer notification quit-application
[task 2024-01-21T15:40:54.950Z] 15:40:54     INFO - PID 7500 | 1705851654949	Marionette	TRACE	Received observer notification quit-application
[task 2024-01-21T15:40:54.951Z] 15:40:54     INFO - PID 7500 | 1705851654949	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.introCount
[task 2024-01-21T15:40:54.952Z] 15:40:54     INFO - PID 7500 | 1705851654950	RemoteAgent	DEBUG	Resetting recommended pref browser.search.update
[task 2024-01-21T15:40:54.953Z] 15:40:54     INFO - PID 7500 | 1705851654950	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.closeWindowWithLastTab
[task 2024-01-21T15:40:54.954Z] 15:40:54     INFO - PID 7500 | 1705851654951	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnClose
[task 2024-01-21T15:40:54.954Z] 15:40:54     INFO - PID 7500 | 1705851654951	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2024-01-21T15:40:54.955Z] 15:40:54     INFO - PID 7500 | 1705851654952	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnOpen
[task 2024-01-21T15:40:54.956Z] 15:40:54     INFO - PID 7500 | 1705851654952	RemoteAgent	DEBUG	Resetting recommended pref browser.usedOnWindows10.introURL
[task 2024-01-21T15:40:54.956Z] 15:40:54     INFO - PID 7500 | 1705851654953	RemoteAgent	DEBUG	Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2024-01-21T15:40:54.957Z] 15:40:54     INFO - PID 7500 | 1705851654953	RemoteAgent	DEBUG	Resetting recommended pref dom.navigation.locationChangeRateLimit.count
[task 2024-01-21T15:40:54.958Z] 15:40:54     INFO - PID 7500 | 1705851654954	RemoteAgent	DEBUG	Resetting recommended pref dom.screenorientation.allow-lock
[task 2024-01-21T15:40:54.958Z] 15:40:54     INFO - PID 7500 | 1705851654954	RemoteAgent	DEBUG	Resetting recommended pref network.connectivity-service.enabled
[task 2024-01-21T15:40:54.959Z] 15:40:54     INFO - PID 7500 | 1705851654955	RemoteAgent	DEBUG	Resetting recommended pref privacy.trackingprotection.enabled
[task 2024-01-21T15:40:54.960Z] 15:40:54     INFO - PID 7500 | 1705851654955	RemoteAgent	DEBUG	Resetting recommended pref security.fileuri.strict_origin_policy
[task 2024-01-21T15:40:54.961Z] 15:40:54     INFO - PID 7500 | 1705851654955	RemoteAgent	DEBUG	Resetting recommended pref signon.autofillForms
[task 2024-01-21T15:40:54.962Z] 15:40:54     INFO - PID 7500 | 1705851654961	RemoteAgent	DEBUG	Resetting recommended pref widget.windows.window_occlusion_tracking.enabled
[task 2024-01-21T15:40:54.963Z] 15:40:54     INFO - PID 7500 | 1705851654962	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-21T15:40:54.964Z] 15:40:54     INFO - PID 7500 | 1705851654962	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-21T15:40:54.964Z] 15:40:54     INFO - PID 7500 | 1705851654962	RemoteAgent	TRACE	Received observer notification quit-application
[task 2024-01-21T15:40:54.965Z] 15:40:54     INFO - PID 7500 | 1705851654965	Marionette	DEBUG	Marionette stopped listening
[task 2024-01-21T15:40:54.981Z] 15:40:54     INFO - PID 7500 | 1705851654980	Marionette	DEBUG	0 <- [1,738,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2024-01-21T15:40:54.997Z] 15:40:54     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: DispatchEvent called on non-current inner window, dropping. Please check the window in the caller instead.: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowInner.cpp:4205
[task 2024-01-21T15:40:54.998Z] 15:40:54     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: DispatchEvent called on non-current inner window, dropping. Please check the window in the caller instead.: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowInner.cpp:4205
[task 2024-01-21T15:40:55.019Z] 15:40:55     INFO - PID 7500 | [GPU 7164, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
[task 2024-01-21T15:40:55.021Z] 15:40:55     INFO - PID 7500 | 1705851655020	webdriver::server	DEBUG	Teardown session
[task 2024-01-21T15:40:55.022Z] 15:40:55     INFO - PID 7500 | 1705851655021	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session 31416ead-c554-456a-ab23-073bf9585e9b is being destroyed
[task 2024-01-21T15:40:55.023Z] 15:40:55     INFO - PID 7500 | 1705851655021	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session 31416ead-c554-456a-ab23-073bf9585e9b
[task 2024-01-21T15:40:55.028Z] 15:40:55     INFO - PID 7500 | 1705851655027	Marionette	DEBUG	Closed connection 0
[task 2024-01-21T15:40:55.041Z] 15:40:55     INFO - PID 7500 | [Parent 1876, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:232
[task 2024-01-21T15:40:55.042Z] 15:40:55     INFO - PID 7500 | !!! error running onStopped callback: TypeError: callback is not a function
[task 2024-01-21T15:40:55.059Z] 15:40:55     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x8046001E (NS_ERROR_ILLEGAL_DURING_SHUTDOWN): file /builds/worker/checkouts/gecko/toolkit/components/credentialmanagement/IdentityCredentialStorageService.cpp:55
[task 2024-01-21T15:40:55.060Z] 15:40:55     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: NS_ENSURE_TRUE(inst) failed: file StaticComponents.cpp:11678
[task 2024-01-21T15:40:55.065Z] 15:40:55     INFO - PID 7500 | console.error: ({})
[task 2024-01-21T15:40:55.077Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.078Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.079Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.080Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.081Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.081Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.083Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.084Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.085Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.085Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.086Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.087Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.088Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.089Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.090Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.091Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.092Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.092Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.093Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.094Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.094Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.095Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:55.096Z] 15:40:55     INFO - PID 7500 | [Child 5808, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:545
[task 2024-01-21T15:40:57.400Z] 15:40:57     INFO - PID 7500 | console.error: (new Error("Data is not ready.", "resource://gre/modules/JSONFile.sys.mjs", 178))
[task 2024-01-21T15:40:57.413Z] 15:40:57     INFO - PID 7500 | 1705851657422	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-21T15:40:57.413Z] 15:40:57     INFO - PID 7500 | 1705851657422	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-21T15:40:57.425Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.426Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.427Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.430Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.431Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.431Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.432Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.434Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.434Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.435Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.436Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.437Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.438Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.439Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.440Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.441Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.442Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.442Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.443Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.444Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:402
[task 2024-01-21T15:40:57.445Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: immediately shutting-down already-dead process: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:2776
[task 2024-01-21T15:40:57.446Z] 15:40:57     INFO - PID 7500 | [Parent 1876, Main Thread] WARNING: failed to launch child in the parent: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:2709
[task 2024-01-21T15:40:57.446Z] 15:40:57     INFO - PID 7500 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to C:\Users\task_170585054678944\AppData\Local\Temp\tmpeeufg652.mozrunner\runtests_leaks_9764_tab_pid3136.log
[task 2024-01-21T15:40:57.455Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.456Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.457Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: idb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.457Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: cache: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.458Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: sdb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.459Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: fs: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.460Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: ls: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.461Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.461Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.462Z] 15:40:57     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:40:57.478Z] 15:40:57     INFO - PID 7500 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2024-01-21T15:40:57.484Z] 15:40:57     INFO - PID 7500 | [Child 3136, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:402
[task 2024-01-21T15:41:02.912Z] 15:41:02     INFO - PID 7500 | [Parent 1876, IPDL Background] WARNING: quota manager shutdown step: '5.453000s: killActorsTimerCallback', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2218
[task 2024-01-21T15:41:09.950Z] 15:41:09     INFO - PID 7500 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.sys.mjs", 370))
[task 2024-01-21T15:41:39.342Z] 15:41:39     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/network/response_started/response_started.py | expected OK
[task 2024-01-21T15:41:39.342Z] 15:41:39     INFO - TEST-INFO took 105004ms
[task 2024-01-21T15:41:44.345Z] 15:41:44     INFO - STDERR: Traceback (most recent call last):
[task 2024-01-21T15:41:44.355Z] 15:41:44     INFO - STDERR:   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 616, in _custom_wait
[task 2024-01-21T15:41:44.355Z] 15:41:44     INFO -     item = self._process_events.get(timeout=timeout)
[task 2024-01-21T15:41:44.356Z] 15:41:44     INFO - STDERR:   File "c:\mozilla-build\python3\lib\queue.py", line 179, in get
[task 2024-01-21T15:41:44.356Z] 15:41:44     INFO -     raise Empty
[task 2024-01-21T15:41:44.356Z] 15:41:44     INFO - STDERR: _queue.Empty
[task 2024-01-21T15:41:44.357Z] 15:41:44     INFO - STDERR: IO Completion Port unexpectedly closed
[task 2024-01-21T15:41:44.358Z] 15:41:44     INFO - Closing logging queue
[task 2024-01-21T15:41:44.358Z] 15:41:44     INFO - queue closed
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - Uncaught exception in TestRunnerManager.run:
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - Traceback (most recent call last):
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 616, in _custom_wait
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -     item = self._process_events.get(timeout=timeout)
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -   File "c:\mozilla-build\python3\lib\queue.py", line 179, in get
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -     raise Empty
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - _queue.Empty
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - 
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - During handling of the above exception, another exception occurred:
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - 
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL - Traceback (most recent call last):
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 400, in run_loop
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -     new_state = f()
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 843, in restart_runner
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -     self.stop_runner(force=self.state.force_stop)
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 864, in stop_runner
[task 2024-01-21T15:41:44.361Z] 15:41:44 CRITICAL -     self.browser.stop(force=force)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 242, in stop
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     self.browser.stop(force=force)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\browsers\firefox.py", line 995, in stop
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     super().stop(force=force)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\tests\web-platform\tests\tools\wptrunner\wptrunner\browsers\base.py", line 375, in stop
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     kill_result = self._proc.kill(timeout=5)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 877, in kill
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     self.proc.kill(sig=sig, timeout=timeout)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 240, in kill
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     self.returncode = self.wait(timeout)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 261, in wait
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     self.returncode = self._custom_wait(timeout=timeout)
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -   File "Z:\task_170585054678944\build\venv\lib\site-packages\mozprocess\processhandler.py", line 622, in _custom_wait
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL -     raise OSError(
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL - OSError: IO Completion Port failed to signal process shutdown
[task 2024-01-21T15:41:44.362Z] 15:41:44 CRITICAL - 
[task 2024-01-21T15:41:44.373Z] 15:41:44     INFO - No more tests
[task 2024-01-21T15:41:44.373Z] 15:41:44 CRITICAL - Tests left in the queue: '/webdriver/tests/bidi/script/classic_interop/node_shared_id.py' and 77 others
[task 2024-01-21T15:42:01.742Z] 15:42:01  WARNING - Firefox didn't exit cleanly, not processing leak logs
[task 2024-01-21T15:42:01.744Z] 15:42:01  WARNING - Command left in remote_queue during cleanup: 'stop', ()
[task 2024-01-21T15:42:01.745Z] 15:42:01     INFO - STDERR: Exception in thread 

Comment 1

[Iulian Moraru]

Hi Henrik! I'm not sure what is going on here. Can you please take a look at this - in case this is a duplicate for some other bug?
Thank you!

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-01-15&endday=2024-01-21&tree=all

Comment 3

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

This is a shutdown hang of Firefox. I re-classified for bug 1630162.

Comment 4

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444395543&repo=autoland

Comment 5

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

(In reply to Treeherder Bug Filer from comment #4)

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444395543&repo=autoland

This is just bug 1838145.

Comment 6

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444424375&repo=mozilla-central

Comment 7

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

(In reply to Treeherder Bug Filer from comment #6)

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444424375&repo=mozilla-central

This is again bug 1838145.

FYI Sandor, in these cases you want to scroll down the error log a bit given that pytest shows the top frame of the stack first and drills down deeper later on.

Comment 8

[Sandor Molnar[:smolnar]]

All right,thank you for the heads-up.
will keep in mind.

Comment 9

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=445370654&repo=autoland

Comment 10

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

(In reply to Treeherder Bug Filer from comment #9)

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=445370654&repo=autoland

This is bug 1838145.

Comment 11

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=445815158&repo=mozilla-beta

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows11-64-2009-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-01-29&endday=2024-02-04&tree=all

Comment 13

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=447771579&repo=mozilla-beta

Comment 14

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=452215361&repo=mozilla-beta

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 2
• mozilla-central: 1

Platform and build breakdown:

• windows11-32-2009-qr: 1
  • debug: 1
• windows11-64-2009-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-03-25&endday=2024-03-31&tree=all

Comment 16

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 2
• autoland: 1

Platform and build breakdown:

• windows11-32-2009-shippable-qr: 1
  • opt: 1
• windows11-64-2009-shippable-qr: 1
  • opt: 1
• windows11-64-2009-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-04-01&endday=2024-04-07&tree=all

Comment 17

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-04-29&endday=2024-05-05&tree=all

Comment 18

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2
• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-qr: 2
  • opt: 2
• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-05-20&endday=2024-05-26&tree=all

Comment 19

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-06-17&endday=2024-06-23&tree=all

Comment 20

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Comment 21

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=476552484&repo=mozilla-beta

Comment 22

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• mozilla-beta: 3
• try: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 2
  • opt: 2
• windows11-64-2009-devedition-qr: 2
  • opt: 2
• windows11-32-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-09-30&endday=2024-10-06&tree=all

Comment 23

[Julian Descottes [:jdescottes]]

The new failure is related to request_timing_info and should be addressed by https://bugzilla.mozilla.org/show_bug.cgi?id=1922390

Comment 24

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 8
• try: 1

Platform and build breakdown:

• windows11-64-2009-devedition-qr: 4
  • opt: 4
• windows11-32-2009-shippable-qr: 1
  • opt: 1
• linux1804-64-tsan-qr: 1
  • opt: 1
• windows11-64-2009-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-10-07&endday=2024-10-13&tree=all

Comment 25

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 4
• autoland: 1
• try: 3

Platform and build breakdown:

• windows11-32-2009-shippable-qr: 2
  • opt: 2
• windows11-64-2009-devedition-qr: 3
  • opt: 3
• windows11-32-2009-qr: 1
  • opt: 1
• windows11-64-2009-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1875706&startday=2024-10-14&endday=2024-10-20&tree=all

Comment 26

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

(In reply to Julian Descottes [:jdescottes] from comment #23)

The new failure is related to request_timing_info and should be addressed by https://bugzilla.mozilla.org/show_bug.cgi?id=1922390

There is still a very low failure rate for this comparision of timings on autoland.