1871481 - Intermittent TEST-UNEXPECTED-TIMEOUT /webdriver/tests/classic/get_element_attribute/get.py | single tracking bug

Status: RESOLVED INCOMPLETE

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-12-21T20:03:16.661Z] 20:03:16     INFO - TEST-START | /webdriver/tests/classic/get_element_attribute/get.py
[task 2023-12-21T20:03:16.990Z] 20:03:16     INFO - STDOUT: ============================= test session starts =============================
[task 2023-12-21T20:03:16.997Z] 20:03:16     INFO - STDOUT: platform win32 -- Python 3.9.10, pytest-7.0.1, pluggy-unknown -- Z:\task_170318488631063\build\venv\Scripts\python.exe
[task 2023-12-21T20:03:16.998Z] 20:03:16     INFO - STDOUT: rootdir: Z:\task_170318488631063\build
[task 2023-12-21T20:03:16.998Z] 20:03:16     INFO - STDOUT: plugins: asyncio-0.19.0
[task 2023-12-21T20:03:16.999Z] 20:03:16     INFO - STDOUT: asyncio: mode=strict
[task 2023-12-21T20:03:16.999Z] 20:03:16     INFO - STDOUT: collecting ... 
[task 2023-12-21T20:03:17.021Z] 20:03:17     INFO - STDOUT: collected 32 items
[task 2023-12-21T20:03:17.030Z] 20:03:17     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/classic/get_element_attribute/get.py::test_no_top_browsing_context 
[task 2023-12-21T20:03:17.033Z] 20:03:17     INFO - PID 5124 | 1703188997032	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "C:\\Users\\task_170318488631 ... "R_LOG_DESTINATION": "stderr", "R_LOG_VERBOSE": "1", "NSS_MAX_MP_PBE_ITERATION_COUNT": "10", "MOZ_WINDOW_OCCLUSION": "0"}}}}}
[task 2023-12-21T20:03:17.034Z] 20:03:17     INFO - PID 5124 | 1703188997032	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2023-12-21T20:03:17.035Z] 20:03:17     INFO - PID 5124 | 1703188997033	geckodriver::capabilities	DEBUG	Found version 123.0a1
[task 2023-12-21T20:03:17.035Z] 20:03:17     INFO - PID 5124 | 1703188997034	geckodriver::browser	DEBUG	Backing up prefs to "C:\\Users\\task_170318488631063\\AppData\\Local\\Temp\\tmpiowq1koj.mozrunner\\user.geckodriver_backup"
[task 2023-12-21T20:03:17.047Z] 20:03:17     INFO - PID 5124 | 1703188997048	mozrunner::runner	INFO	Running command: "Z:\\task_170318488631063\\build\\application\\firefox\\firefox.exe" "--marionette" "--profile" "C:\\Users\\task_170318488631063\\AppData\\Local\\Temp\\tmpiowq1koj.mozrunner" "-no-remote"
[task 2023-12-21T20:03:17.054Z] 20:03:17     INFO - PID 5124 | 1703188997053	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2023-12-21T20:03:17.055Z] 20:03:17     INFO - PID 5124 | 1703188997053	geckodriver::browser	TRACE	Failed to open C:\Users\task_170318488631063\AppData\Local\Temp\tmpiowq1koj.mozrunner\MarionetteActivePort
[task 2023-12-21T20:03:17.056Z] 20:03:17     INFO - PID 5124 | 1703188997053	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2023-12-21T20:03:17.161Z] 20:03:17     INFO - PID 5124 | 1703188997161	geckodriver::browser	TRACE	Failed to open C:\Users\task_170318488631063\AppData\Local\Temp\tmpiowq1koj.mozrunner\MarionetteActivePort
[task 2023-12-21T20:03:17.164Z] 20:03:17     INFO - PID 5124 | 1703188997162	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2023-12-21T20:03:17.271Z] 20:03:17     INFO - PID 5124 | 1703188997271	geckodriver::browser	TRACE	Failed to open C:\Users\task_170318488631063\AppData\Local\Temp\tmpiowq1koj.mozrunner\MarionetteActivePort
[task 2023-12-21T20:03:17.273Z] 20:03:17     INFO - PID 5124 | 1703188997271	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2023-12-21T20:03:17.318Z] 20:03:17     INFO - PID 5124 | 1703188997319	Marionette	INFO	Marionette enabled
[task 2023-12-21T20:03:17.321Z] 20:03:17     INFO - PID 5124 | 1703188997320	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-12-21T20:03:17.334Z] 20:03:17     INFO - PID 5124 | 1703188997336	Marionette	INFO	Listening on port 53323
[task 2023-12-21T20:03:17.339Z] 20:03:17     INFO - PID 5124 | 1703188997337	Marionette	DEBUG	Marionette is listening
[task 2023-12-21T20:03:17.381Z] 20:03:17     INFO - PID 5124 | Read port: 53323
[task 2023-12-21T20:03:17.428Z] 20:03:17     INFO - PID 5124 | 1703188997436	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:53324
[task 2023-12-21T20:03:17.441Z] 20:03:17     INFO - PID 5124 | 1703188997441	geckodriver::marionette	DEBUG	Connection to Marionette established on 127.0.0.1:53323.
[task 2023-12-21T20:03:17.460Z] 20:03:17     INFO - PID 5124 | 1703188997468	Marionette	DEBUG	0 -> [0,1,"WebDriver:NewSession",{}]
[task 2023-12-21T20:03:17.471Z] 20:03:17     INFO - PID 5124 | 1703188997469	Marionette	DEBUG	Waiting for initial application window
[task 2023-12-21T20:03:17.569Z] 20:03:17     INFO - PID 5124 | [ERROR firefox_on_glean::private::string] Unable to set string metric in non-main process. Ignoring.
<...>
[task 2023-12-21T20:03:29.601Z] 20:03:29     INFO - STDOUT: PASSED
[task 2023-12-21T20:03:29.602Z] 20:03:29     INFO - PID 5124 | 1703189009580	Marionette	TRACE	[70] Received event DOMContentLoaded for https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Ca+href%3D%27https%3A%2F%2Fweb-platform.test%3A8443%2Ffoo.html%27%3Efoo%3C%2Fa%3E&mime=text%2Fhtml&charset=UTF-8
[task 2023-12-21T20:03:29.605Z] 20:03:29     INFO - PID 5124 | 1703189009580	Marionette	TRACE	[70] Received event pageshow for https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Ca+href%3D%27https%3A%2F%2Fweb-platform.test%3A8443%2Ffoo.html%27%3Efoo%3C%2Fa%3E&mime=text%2Fhtml&charset=UTF-8
[task 2023-12-21T20:03:29.605Z] 20:03:29     INFO - PID 5124 | 1703189009580	Marionette	DEBUG	0 <- [1,814,null,{"value":null}]
[task 2023-12-21T20:03:29.606Z] 20:03:29     INFO - PID 5124 | 1703189009583	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.607Z] 20:03:29     INFO - PID 5124 | 1703189009584	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/element {"using": "css selector", "value": "a"}
[task 2023-12-21T20:03:29.609Z] 20:03:29     INFO - PID 5124 | 1703189009585	Marionette	DEBUG	0 -> [0,815,"WebDriver:FindElement",{"using":"css selector","value":"a"}]
[task 2023-12-21T20:03:29.609Z] 20:03:29     INFO - PID 5124 | 1703189009585	Marionette	TRACE	[70] MarionetteCommands actor created for window id 25769803845
[task 2023-12-21T20:03:29.610Z] 20:03:29     INFO - PID 5124 | 1703189009586	Marionette	DEBUG	0 <- [1,815,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"0e6f08bb-fc98-4788-accf-fd4833068dc6"}}]
[task 2023-12-21T20:03:29.611Z] 20:03:29     INFO - PID 5124 | 1703189009586	webdriver::server	DEBUG	<- 200 OK {"value":{"element-6066-11e4-a52e-4f735466cecf":"0e6f08bb-fc98-4788-accf-fd4833068dc6"}}
[task 2023-12-21T20:03:29.612Z] 20:03:29     INFO - PID 5124 | 1703189009587	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/element/0e6f08bb-fc98-4788-accf-fd4833068dc6/attribute/href
[task 2023-12-21T20:03:29.613Z] 20:03:29     INFO - PID 5124 | 1703189009588	Marionette	DEBUG	0 -> [0,816,"WebDriver:GetElementAttribute",{"id":"0e6f08bb-fc98-4788-accf-fd4833068dc6","name":"href"}]
[task 2023-12-21T20:03:29.614Z] 20:03:29     INFO - PID 5124 | 1703189009588	Marionette	DEBUG	0 <- [1,816,null,{"value":"https://web-platform.test:8443/foo.html"}]
[task 2023-12-21T20:03:29.614Z] 20:03:29     INFO - PID 5124 | 1703189009589	webdriver::server	DEBUG	<- 200 OK {"value":"https://web-platform.test:8443/foo.html"}
[task 2023-12-21T20:03:29.615Z] 20:03:29     INFO - PID 5124 | 1703189009591	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/timeouts {"implicit": 0}
[task 2023-12-21T20:03:29.616Z] 20:03:29     INFO - PID 5124 | 1703189009591	Marionette	DEBUG	0 -> [0,817,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-12-21T20:03:29.617Z] 20:03:29     INFO - PID 5124 | 1703189009591	Marionette	DEBUG	0 <- [1,817,null,{"value":null}]
[task 2023-12-21T20:03:29.618Z] 20:03:29     INFO - PID 5124 | 1703189009592	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.618Z] 20:03:29     INFO - PID 5124 | 1703189009593	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/timeouts {"pageLoad": 300000}
[task 2023-12-21T20:03:29.619Z] 20:03:29     INFO - PID 5124 | 1703189009593	Marionette	DEBUG	0 -> [0,818,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-12-21T20:03:29.620Z] 20:03:29     INFO - PID 5124 | 1703189009593	Marionette	DEBUG	0 <- [1,818,null,{"value":null}]
[task 2023-12-21T20:03:29.621Z] 20:03:29     INFO - PID 5124 | 1703189009593	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.622Z] 20:03:29     INFO - PID 5124 | 1703189009594	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/timeouts {"script": 30000}
[task 2023-12-21T20:03:29.622Z] 20:03:29     INFO - PID 5124 | 1703189009595	Marionette	DEBUG	0 -> [0,819,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-12-21T20:03:29.623Z] 20:03:29     INFO - PID 5124 | 1703189009595	Marionette	DEBUG	0 <- [1,819,null,{"value":null}]
[task 2023-12-21T20:03:29.624Z] 20:03:29     INFO - PID 5124 | 1703189009595	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.624Z] 20:03:29     INFO - PID 5124 | 1703189009596	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window
[task 2023-12-21T20:03:29.625Z] 20:03:29     INFO - PID 5124 | 1703189009596	Marionette	DEBUG	0 -> [0,820,"WebDriver:GetWindowHandle",{}]
[task 2023-12-21T20:03:29.626Z] 20:03:29     INFO - PID 5124 | 1703189009596	Marionette	DEBUG	0 <- [1,820,null,{"value":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.626Z] 20:03:29     INFO - PID 5124 | 1703189009597	webdriver::server	DEBUG	<- 200 OK {"value":"55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.627Z] 20:03:29     INFO - PID 5124 | 1703189009597	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window
[task 2023-12-21T20:03:29.628Z] 20:03:29     INFO - PID 5124 | 1703189009598	Marionette	DEBUG	0 -> [0,821,"WebDriver:GetWindowHandle",{}]
[task 2023-12-21T20:03:29.628Z] 20:03:29     INFO - PID 5124 | 1703189009598	Marionette	DEBUG	0 <- [1,821,null,{"value":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.629Z] 20:03:29     INFO - PID 5124 | 1703189009598	webdriver::server	DEBUG	<- 200 OK {"value":"55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.630Z] 20:03:29     INFO - PID 5124 | 1703189009599	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window/handles
[task 2023-12-21T20:03:29.631Z] 20:03:29     INFO - PID 5124 | 1703189009599	Marionette	DEBUG	0 -> [0,822,"WebDriver:GetWindowHandles",{}]
[task 2023-12-21T20:03:29.632Z] 20:03:29     INFO - PID 5124 | 1703189009599	Marionette	DEBUG	0 <- [1,822,null,["55701e09-2050-4698-baac-9aab44fcaf92"]]
[task 2023-12-21T20:03:29.634Z] 20:03:29     INFO - PID 5124 | 1703189009603	webdriver::server	DEBUG	<- 200 OK {"value":["55701e09-2050-4698-baac-9aab44fcaf92"]}
[task 2023-12-21T20:03:29.635Z] 20:03:29     INFO - PID 5124 | 1703189009604	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window {"handle": "55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.636Z] 20:03:29     INFO - PID 5124 | 1703189009605	Marionette	DEBUG	0 -> [0,823,"WebDriver:SwitchToWindow",{"handle":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.637Z] 20:03:29     INFO - PID 5124 | 1703189009605	Marionette	DEBUG	0 <- [1,823,null,{"value":null}]
[task 2023-12-21T20:03:29.639Z] 20:03:29     INFO - PID 5124 | 1703189009606	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.639Z] 20:03:29     INFO - PID 5124 | 1703189009607	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/alert/dismiss {}
[task 2023-12-21T20:03:29.640Z] 20:03:29     INFO - PID 5124 | 1703189009608	Marionette	DEBUG	0 -> [0,824,"WebDriver:DismissAlert",{}]
[task 2023-12-21T20:03:29.642Z] 20:03:29     INFO - PID 5124 | 1703189009608	Marionette	DEBUG	0 <- [1,824,{"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 2023-12-21T20:03:29.643Z] 20:03:29     INFO - PID 5124 | 1703189009608	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 2023-12-21T20:03:29.644Z] 20:03:29     INFO - PID 5124 | 1703189009609	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window {"handle": "55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.646Z] 20:03:29     INFO - PID 5124 | 1703189009610	Marionette	DEBUG	0 -> [0,825,"WebDriver:SwitchToWindow",{"handle":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.647Z] 20:03:29     INFO - PID 5124 | 1703189009610	Marionette	DEBUG	0 <- [1,825,null,{"value":null}]
[task 2023-12-21T20:03:29.648Z] 20:03:29     INFO - PID 5124 | 1703189009610	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.649Z] 20:03:29     INFO - PID 5124 | 1703189009611	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window
[task 2023-12-21T20:03:29.651Z] 20:03:29     INFO - PID 5124 | 1703189009611	Marionette	DEBUG	0 -> [0,826,"WebDriver:GetWindowHandle",{}]
[task 2023-12-21T20:03:29.652Z] 20:03:29     INFO - PID 5124 | 1703189009611	Marionette	DEBUG	0 <- [1,826,null,{"value":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.653Z] 20:03:29     INFO - PID 5124 | 1703189009612	webdriver::server	DEBUG	<- 200 OK {"value":"55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.654Z] 20:03:29     INFO - PID 5124 | 1703189009613	webdriver::server	DEBUG	-> GET /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window/handles
[task 2023-12-21T20:03:29.655Z] 20:03:29     INFO - PID 5124 | 1703189009613	Marionette	DEBUG	0 -> [0,827,"WebDriver:GetWindowHandles",{}]
[task 2023-12-21T20:03:29.656Z] 20:03:29     INFO - PID 5124 | 1703189009613	Marionette	DEBUG	0 <- [1,827,null,["55701e09-2050-4698-baac-9aab44fcaf92"]]
[task 2023-12-21T20:03:29.657Z] 20:03:29     INFO - PID 5124 | 1703189009613	webdriver::server	DEBUG	<- 200 OK {"value":["55701e09-2050-4698-baac-9aab44fcaf92"]}
[task 2023-12-21T20:03:29.658Z] 20:03:29     INFO - PID 5124 | 1703189009614	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window {"handle": "55701e09-2050-4698-baac-9aab44fcaf92"}
[task 2023-12-21T20:03:29.658Z] 20:03:29     INFO - PID 5124 | 1703189009615	Marionette	DEBUG	0 -> [0,828,"WebDriver:SwitchToWindow",{"handle":"55701e09-2050-4698-baac-9aab44fcaf92"}]
[task 2023-12-21T20:03:29.659Z] 20:03:29     INFO - PID 5124 | 1703189009615	Marionette	DEBUG	0 <- [1,828,null,{"value":null}]
[task 2023-12-21T20:03:29.660Z] 20:03:29     INFO - PID 5124 | 1703189009615	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.661Z] 20:03:29     INFO - PID 5124 | 1703189009616	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/window/rect {"width": 800, "height": 600}
[task 2023-12-21T20:03:29.661Z] 20:03:29     INFO - PID 5124 | 1703189009616	Marionette	DEBUG	0 -> [0,829,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2023-12-21T20:03:29.662Z] 20:03:29     INFO - PID 5124 | 1703189009616	Marionette	TRACE	Requested window geometry matches
[task 2023-12-21T20:03:29.663Z] 20:03:29     INFO - PID 5124 | 1703189009617	Marionette	DEBUG	0 <- [1,829,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2023-12-21T20:03:29.664Z] 20:03:29     INFO - PID 5124 | 1703189009617	webdriver::server	DEBUG	<- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2023-12-21T20:03:29.665Z] 20:03:29     INFO - PID 5124 | 1703189009618	webdriver::server	DEBUG	-> POST /session/83396968-d89f-4935-b498-a4ce9dab0a6e/frame {"id": null}
[task 2023-12-21T20:03:29.666Z] 20:03:29     INFO - PID 5124 | 1703189009618	Marionette	DEBUG	0 -> [0,830,"WebDriver:SwitchToFrame",{"id":null}]
[task 2023-12-21T20:03:29.666Z] 20:03:29     INFO - PID 5124 | 1703189009619	Marionette	DEBUG	0 <- [1,830,null,{"value":null}]
[task 2023-12-21T20:03:29.667Z] 20:03:29     INFO - PID 5124 | 1703189009619	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-12-21T20:03:29.667Z] 20:03:29     INFO - PID 5124 | 1703189009624	webdriver::server	DEBUG	-> DELETE /session/83396968-d89f-4935-b498-a4ce9dab0a6e
[task 2023-12-21T20:03:29.668Z] 20:03:29     INFO - PID 5124 | 1703189009625	Marionette	DEBUG	0 -> [0,831,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2023-12-21T20:03:29.669Z] 20:03:29     INFO - PID 5124 | 1703189009625	Marionette	INFO	Stopped listening on port 53323
[task 2023-12-21T20:03:29.669Z] 20:03:29     INFO - PID 5124 | 1703189009637	Marionette	TRACE	[68] MarionetteCommands actor destroyed for window id 25769803843
[task 2023-12-21T20:03:29.670Z] 20:03:29     INFO - PID 5124 | 1703189009637	Marionette	TRACE	[67] MarionetteCommands actor destroyed for window id 25769803842
[task 2023-12-21T20:03:29.671Z] 20:03:29     INFO - PID 5124 | 1703189009637	Marionette	TRACE	[69] MarionetteCommands actor destroyed for window id 25769803844
[task 2023-12-21T20:03:29.672Z] 20:03:29     INFO - PID 5124 | 1703189009637	Marionette	TRACE	[70] MarionetteCommands actor destroyed for window id 25769803845
[task 2023-12-21T20:03:29.683Z] 20:03:29     INFO - PID 5124 | 1703189009682	Marionette	TRACE	Received observer notification quit-application
[task 2023-12-21T20:03:29.686Z] 20:03:29     INFO - PID 5124 | 1703189009685	Marionette	TRACE	Received observer notification quit-application
[task 2023-12-21T20:03:29.687Z] 20:03:29     INFO - PID 5124 | 1703189009686	Marionette	DEBUG	Marionette stopped listening
[task 2023-12-21T20:03:29.688Z] 20:03:29     INFO - PID 5124 | 1703189009686	Marionette	DEBUG	0 <- [1,831,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2023-12-21T20:03:29.705Z] 20:03:29     INFO - PID 5124 | 1703189009704	webdriver::server	DEBUG	Teardown session
[task 2023-12-21T20:03:29.710Z] 20:03:29     INFO - PID 5124 | 1703189009709	Marionette	DEBUG	Closed connection 0
[task 2023-12-21T20:03:29.721Z] 20:03:29     INFO - PID 5124 | console.error: ({})
[task 2023-12-21T20:03:41.506Z] 20:03:41     INFO - PID 5124 | console.error: (new AbortError("IndexedDB: main/doh-config list() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2023-12-21T20:03:41.515Z] 20:03:41     INFO - PID 5124 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 722: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "DoHController: clear state and remove observers"
[task 2023-12-21T20:03:44.693Z] 20:03:44     INFO - PID 5124 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.sys.mjs", 370))
[task 2023-12-21T20:03:46.673Z] 20:03:46     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/classic/get_element_attribute/get.py | expected OK
[task 2023-12-21T20:03:46.673Z] 20:03:46     INFO - TEST-INFO took 30012ms
[task 2023-12-21T20:03:50.535Z] 20:03:50     INFO - Closing logging queue
[task 2023-12-21T20:03:50.544Z] 20:03:50     INFO - queue closed
[task 2023-12-21T20:03:50.660Z] 20:03:50     INFO - PID 2612 | 1703189030565	geckodriver	INFO	Listening on 127.0.0.1:54288
[task 2023-12-21T20:03:50.663Z] 20:03:50     INFO - Starting runner
[task 2023-12-21T20:03:51.661Z] 20:03:51     INFO - TEST-START | /webdriver/tests/classic/get_element_attribute/user_prompts.py

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 07/21 - 08/08)]

That's a delayed shutdown of Firefox, but it's not clear to me if the doh-config list() might cause that. Mathieu, are you able to help with that?

Comment 2

[Intermittent Failures Robot]

1 failures in 3349 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-32-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1871481&startday=2023-12-18&endday=2023-12-24&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• try: 1

Platform and build breakdown:

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

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

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• android-em-7-0-x86_64-lite-qr: 1
  • opt: 1

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

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 1
  • opt: 1

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

Comment 6

[Intermittent Failures Robot]

1 failures in 4034 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-32-2009-shippable-qr: 1
  • opt: 1

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

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

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

Platform and build breakdown:

• linux1804-64-tsan-qr: 1
  • opt: 1
• android-em-7-0-x86_64-qr: 1
  • debug: 1

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

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 07/21 - 08/08)]

All the classified failures on this bug for the last nearly two months are unrelated and I've re-classified. Closing this bug as incomplete for now.

Comment 9

[Treeherder Bug Filer]

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

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 07/21 - 08/08)]

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

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

This failure is just bug 1825501. I've re-classified.