Open Bug 1877539 Opened 9 months ago Updated 5 days ago

Intermittent TEST-UNEXPECTED-TIMEOUT /_mozilla/webdriver/bidi/browser/close/close.py | single tracking bug

Categories

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

defect

Tracking

(Not tracked)

REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure, intermittent-testcase)

Attachments

(1 obsolete file)

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


[task 2024-01-30T20:07:25.560Z] 20:07:25     INFO - TEST-START | /_mozilla/webdriver/bidi/browser/close/close.py
[task 2024-01-30T20:07:26.169Z] 20:07:26     INFO - STDOUT: ============================= test session starts =============================
[task 2024-01-30T20:07:26.172Z] 20:07:26     INFO - STDOUT: platform win32 -- Python 3.9.10, pytest-7.0.1, pluggy-unknown -- Z:\task_170664231575554\build\venv\Scripts\python.exe
[task 2024-01-30T20:07:26.173Z] 20:07:26     INFO - STDOUT: rootdir: Z:\task_170664231575554\build
[task 2024-01-30T20:07:26.174Z] 20:07:26     INFO - STDOUT: plugins: asyncio-0.19.0
[task 2024-01-30T20:07:26.174Z] 20:07:26     INFO - STDOUT: asyncio: mode=strict
[task 2024-01-30T20:07:26.175Z] 20:07:26     INFO - STDOUT: collecting ... 
[task 2024-01-30T20:07:26.201Z] 20:07:26     INFO - STDOUT: collected 2 items
[task 2024-01-30T20:07:26.210Z] 20:07:26     INFO - STDOUT: tests/web-platform/mozilla/tests/webdriver/bidi/browser/close/close.py::test_close_browser 
[task 2024-01-30T20:07:33.328Z] 20:07:33     INFO - STDOUT: *** You are running in headless mode.
[task 2024-01-30T20:07:33.438Z] 20:07:33     INFO - STDOUT: 1706645253446	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2024-01-30T20:07:33.449Z] 20:07:33     INFO - STDOUT: 1706645253446	RemoteAgent	DEBUG	CDP enabled
[task 2024-01-30T20:07:33.449Z] 20:07:33     INFO - STDOUT: 1706645253447	RemoteAgent	TRACE	Received observer notification final-ui-startup
[task 2024-01-30T20:07:33.460Z] 20:07:33     INFO - STDOUT: 1706645253466	RemoteAgent	TRACE	Available local IP addresses: 127.0.0.1, [::1]
[task 2024-01-30T20:07:33.469Z] 20:07:33     INFO - STDOUT: WebDriver BiDi listening on ws://127.0.0.1:52943
[task 2024-01-30T20:07:33.469Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.introCount to 99
[task 2024-01-30T20:07:33.470Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.search.update to false
[task 2024-01-30T20:07:33.471Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.closeWindowWithLastTab to false
[task 2024-01-30T20:07:33.473Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnClose to false
[task 2024-01-30T20:07:33.474Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
[task 2024-01-30T20:07:33.475Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnOpen to false
[task 2024-01-30T20:07:33.476Z] 20:07:33     INFO - STDOUT: 1706645253468	RemoteAgent	DEBUG	Setting recommended pref browser.usedOnWindows10.introURL to
[task 2024-01-30T20:07:33.477Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
[task 2024-01-30T20:07:33.478Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref dom.navigation.locationChangeRateLimit.count to 0
[task 2024-01-30T20:07:33.479Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref dom.screenorientation.allow-lock to true
[task 2024-01-30T20:07:33.480Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref network.connectivity-service.enabled to false
[task 2024-01-30T20:07:33.480Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref privacy.trackingprotection.enabled to false
[task 2024-01-30T20:07:33.481Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref security.fileuri.strict_origin_policy to false
[task 2024-01-30T20:07:33.481Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref signon.autofillForms to false
[task 2024-01-30T20:07:33.482Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref widget.windows.window_occlusion_tracking.enabled to false
[task 2024-01-30T20:07:33.483Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.features.standard to -tp,tpPrivate,cookieBehavior0,-cm,-fp
[task 2024-01-30T20:07:33.484Z] 20:07:33     INFO - STDOUT: 1706645253469	RemoteAgent	DEBUG	Setting recommended pref network.cookie.cookieBehavior to 0
[task 2024-01-30T20:07:33.484Z] 20:07:33     INFO - STDOUT: 1706645253469	CDP	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:33.530Z] 20:07:33     INFO - STDOUT: 1706645253538	RemoteAgent	INFO	Perform WebSocket upgrade for incoming connection from 127.0.0.1:52944
[task 2024-01-30T20:07:33.562Z] 20:07:33     INFO - STDOUT: 1706645253565	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 accepted
[task 2024-01-30T20:07:33.577Z] 20:07:33     INFO - STDOUT: 1706645253567	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 -> {"id":1,"method":"session.new","params":{"capabilities":{"alwaysMatch":{"moz:firefoxOptions":{"args":["--profile","C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmp816441wc.mozrunner"],"env":{"ALLUSERSPROFILE":"C:\\ProgramData","APPDATA":"Z:\\task_170664231575554\\AppData\\Roaming","COMMONPROGRAMFILES":"C:\\Program Files\\Common Files","COMMONPROGRAMFILES(X86)":"C:\\Program Files (x86)\\Common Files","COMMONPROGRAMW6432":"C:\\Program Files\\Common Files","COMPUTERNAME":"VM-RN8GLHSMRRAN","COMSPEC":"C:\\Windows\\system32\\cmd.exe","DRIVERDATA":"C:\\Windows\\System32\\Drivers\\DriverData","EXTRA_MOZHARNESS_CONFIG":"{\"installer_url\": \"https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build ... irefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build/target.test_packages.json\"}","GECKO_HEAD_REPOSITORY":"https://hg.mozilla.org/releases/mozilla-beta","GECKO_HEAD_REV":"814c511db3bf80ee923c7e26d7248df7690afbc7","HG_CACHE":"y:\\hg-cache","HOMEDRIVE":"C:","HOMEPATH":"\\Users\\task_170664231575554","LOCALAPPDATA":"C:\\Users\\task_170664231575554\\AppData\\Local","LOGONSERVER":"\\\\VM-RN8GLHSMRRAN","MOZHARNESS_TEST_PATHS":"{\"web-platform-tests-wdspec\": [\"/_mozilla/webdriver/bidi/browser/close\", \"/_mozilla/webdriver/bidi/browsing_context/set_viewp ... tests/classic/set_timeouts\", \"/webdriver/tests/classic/switch_to_frame\", \"/webdriver/tests/classic/take_element_screenshot\"]}","MOZILLABUILD":"C:\\mozilla-build","MOZ_AUTOMATION":"1","MOZ_FETCHES":"[{\"artifact\": \"public/build/fix-stacks.tar.zst\", \"extract\": true, \"task\": \"N10FEI3dTae7qF8CltO3-A\"}, {\"artifact\": \"public/bui ... SzWi80vEqzs81Q\"}, {\"artifact\": \"public/build/minidump-stackwalk.tar.zst\", \"extract\": true, \"task\": \"CJY1pIAgSAe9zquw6EUMhQ\"}]","MOZ_FETCHES_DIR":"Z:/task_170664231575554/fetches","MOZ_SCM_LEVEL":"3","NUMBER_OF_PROCESSORS":"8","OS":"Windows_NT","PATH":"Z:\\task_170664231575554\\build\\venv\\Scripts;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\Window ... 2\\usr\\bin;C:\\Users\\task_170664231575554\\AppData\\Local\\Microsoft\\WindowsApps;Z:\\task_170664231575554\\build\\application\\firefox","PATHEXT":".COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC","PIP_DOWNLOAD_CACHE":"y:\\pip-cache","PROCESSOR_ARCHITECTURE":"AMD64","PROCESSOR_IDENTIFIER":"Intel64 Family 6 Model 106 Stepping 6, GenuineIntel","PROCESSOR_LEVEL":"6","PROCE [... truncated after 2500 characters]
[task 2024-01-30T20:07:33.578Z] 20:07:33     INFO - STDOUT: 1706645253568	WebDriver BiDi	DEBUG	Connection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 attached to session c7bd5790-39eb-4ddb-b4a6-397484958d39
[task 2024-01-30T20:07:33.580Z] 20:07:33     INFO - STDOUT: 1706645253568	WebDriver BiDi	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:33.671Z] 20:07:33     INFO - STDOUT: [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2024-01-30T20:07:36.057Z] 20:07:36     INFO - STDOUT: console.error: ({})
[task 2024-01-30T20:07:36.089Z] 20:07:36     INFO - STDOUT: 1706645256089	RemoteAgent	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2024-01-30T20:07:36.095Z] 20:07:36     INFO - STDOUT: 1706645256093	WebDriver BiDi	DEBUG	Registered session handler: /session/c7bd5790-39eb-4ddb-b4a6-397484958d39
[task 2024-01-30T20:07:36.098Z] 20:07:36     INFO - STDOUT: 1706645256094	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 <- {"type":"success","id":1,"result":{"sessionId":"c7bd5790-39eb-4ddb-b4a6-397484958d39","capabilities":{"browserName":"firefox","browserVersion":"123.0","platformName":"windows","acceptInsecureCerts":false,"proxy":{},"setWindowRect":true,"moz:accessibilityChecks":false,"moz:buildID":"20240130172221","moz:headless":true,"moz:platformVersion":"10.0","moz:processID":5536,"moz:profile":"C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmp_wj5doc5","moz:shutdownTimeout":60000,"moz:windowless":false}}}
[task 2024-01-30T20:07:36.099Z] 20:07:36     INFO - STDOUT: DevTools listening on ws://127.0.0.1:52943/devtools/browser/3b3453c0-d450-4e44-82d9-a02ebf97fbd0
[task 2024-01-30T20:07:36.100Z] 20:07:36     INFO - STDOUT: 1706645256095	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 -> {"id":2,"method":"browser.close","params":{}}
[task 2024-01-30T20:07:36.103Z] 20:07:36     INFO - STDOUT: 1706645256102	RemoteAgent	TRACE	Registered MessageHandlerFrame actors
[task 2024-01-30T20:07:36.105Z] 20:07:36     INFO - STDOUT: 1706645256104	RemoteAgent	TRACE	Created MessageHandler ROOT for session c7bd5790-39eb-4ddb-b4a6-397484958d39
[task 2024-01-30T20:07:36.107Z] 20:07:36     INFO - STDOUT: 1706645256105	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:36.108Z] 20:07:36     INFO - STDOUT: 1706645256105	RemoteAgent	TRACE	Received command browser.close for destination ROOT
[task 2024-01-30T20:07:36.109Z] 20:07:36     INFO - STDOUT: 1706645256105	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:36.110Z] 20:07:36     INFO - STDOUT: 1706645256105	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:36.111Z] 20:07:36     INFO - STDOUT: 1706645256105	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 <- {"type":"success","id":2,"result":{}}
[task 2024-01-30T20:07:36.112Z] 20:07:36     INFO - STDOUT: 1706645256105	WebDriver BiDi	DEBUG	Unregistered session handler: /session/c7bd5790-39eb-4ddb-b4a6-397484958d39
[task 2024-01-30T20:07:36.113Z] 20:07:36     INFO - STDOUT: 1706645256106	RemoteAgent	DEBUG	WebDriverBiDiConnection 34ffdeca-2673-4cee-904e-e87b5d9ba3b3 closed
[task 2024-01-30T20:07:36.114Z] 20:07:36     INFO - STDOUT: 1706645256107	RemoteAgent	TRACE	MessageHandler ROOT for session c7bd5790-39eb-4ddb-b4a6-397484958d39 is being destroyed
[task 2024-01-30T20:07:36.115Z] 20:07:36     INFO - STDOUT: 1706645256108	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session c7bd5790-39eb-4ddb-b4a6-397484958d39
[task 2024-01-30T20:07:36.136Z] 20:07:36     INFO - STDOUT: 1706645256140	Marionette	TRACE	Received observer notification quit-application
[task 2024-01-30T20:07:36.143Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.introCount
[task 2024-01-30T20:07:36.144Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.search.update
[task 2024-01-30T20:07:36.145Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.closeWindowWithLastTab
[task 2024-01-30T20:07:36.146Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnClose
[task 2024-01-30T20:07:36.148Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2024-01-30T20:07:36.148Z] 20:07:36     INFO - STDOUT: 1706645256141	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnOpen
[task 2024-01-30T20:07:36.150Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref browser.usedOnWindows10.introURL
[task 2024-01-30T20:07:36.151Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2024-01-30T20:07:36.152Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref dom.navigation.locationChangeRateLimit.count
[task 2024-01-30T20:07:36.152Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref dom.screenorientation.allow-lock
[task 2024-01-30T20:07:36.153Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref network.connectivity-service.enabled
[task 2024-01-30T20:07:36.154Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref privacy.trackingprotection.enabled
[task 2024-01-30T20:07:36.155Z] 20:07:36     INFO - STDOUT: 1706645256142	RemoteAgent	DEBUG	Resetting recommended pref security.fileuri.strict_origin_policy
[task 2024-01-30T20:07:36.157Z] 20:07:36     INFO - STDOUT: 1706645256143	RemoteAgent	DEBUG	Resetting recommended pref signon.autofillForms
[task 2024-01-30T20:07:36.158Z] 20:07:36     INFO - STDOUT: 1706645256144	RemoteAgent	DEBUG	Resetting recommended pref widget.windows.window_occlusion_tracking.enabled
[task 2024-01-30T20:07:36.158Z] 20:07:36     INFO - STDOUT: 1706645256144	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-30T20:07:36.159Z] 20:07:36     INFO - STDOUT: 1706645256144	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-30T20:07:36.160Z] 20:07:36     INFO - STDOUT: 1706645256147	RemoteAgent	TRACE	Received observer notification quit-application
[task 2024-01-30T20:07:36.166Z] 20:07:36     INFO - STDOUT: 1706645256164	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-30T20:07:36.167Z] 20:07:36     INFO - STDOUT: 1706645256164	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-30T20:07:39.823Z] 20:07:39     INFO - STDOUT: console.error: (new TypeError("result[0] is undefined", "resource://gre/modules/Sqlite.sys.mjs", 1678))
[task 2024-01-30T20:07:39.836Z] 20:07:39     INFO - STDOUT: console.error: (new Error("IndexedDB: main/hijack-blocklists getLastModified() IndexedDB:  execute() The application is shutting down", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.837Z] 20:07:39     INFO - STDOUT: 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 2024-01-30T20:07:39.839Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: blocklists/gfx getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.840Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.841Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.842Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.843Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.844Z] 20:07:39     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:39.844Z] 20:07:39     INFO - STDOUT: JavaScript error: resource://gre/modules/Sqlite.sys.mjs, line 1678: TypeError: result[0] is undefined
[task 2024-01-30T20:07:39.845Z] 20:07:39     INFO - STDOUT: JavaScript error: resource://gre/modules/Sqlite.sys.mjs, line 1678: TypeError: result[0] is undefined
[task 2024-01-30T20:07:39.846Z] 20:07:39     INFO - STDOUT: JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 719: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "DoHController: clear state and remove observers"
[task 2024-01-30T20:07:40.968Z] 20:07:40     INFO - STDOUT: PASSED
[task 2024-01-30T20:07:40.973Z] 20:07:40     INFO - STDOUT: tests/web-platform/mozilla/tests/webdriver/bidi/browser/close/close.py::test_start_session_again 
[task 2024-01-30T20:07:46.533Z] 20:07:46     INFO - STDOUT: *** You are running in headless mode.
[task 2024-01-30T20:07:46.658Z] 20:07:46     INFO - STDOUT: 1706645266670	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2024-01-30T20:07:46.672Z] 20:07:46     INFO - STDOUT: 1706645266670	RemoteAgent	DEBUG	CDP enabled
[task 2024-01-30T20:07:46.673Z] 20:07:46     INFO - STDOUT: 1706645266671	RemoteAgent	TRACE	Received observer notification final-ui-startup
[task 2024-01-30T20:07:46.690Z] 20:07:46     INFO - STDOUT: 1706645266690	RemoteAgent	TRACE	Available local IP addresses: 127.0.0.1, [::1]
[task 2024-01-30T20:07:46.693Z] 20:07:46     INFO - STDOUT: WebDriver BiDi listening on ws://127.0.0.1:52952
[task 2024-01-30T20:07:46.694Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.introCount to 99
[task 2024-01-30T20:07:46.695Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.search.update to false
[task 2024-01-30T20:07:46.696Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.closeWindowWithLastTab to false
[task 2024-01-30T20:07:46.696Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnClose to false
[task 2024-01-30T20:07:46.698Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
[task 2024-01-30T20:07:46.699Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnOpen to false
[task 2024-01-30T20:07:46.700Z] 20:07:46     INFO - STDOUT: 1706645266692	RemoteAgent	DEBUG	Setting recommended pref browser.usedOnWindows10.introURL to
[task 2024-01-30T20:07:46.701Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
[task 2024-01-30T20:07:46.702Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref dom.navigation.locationChangeRateLimit.count to 0
[task 2024-01-30T20:07:46.702Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref dom.screenorientation.allow-lock to true
[task 2024-01-30T20:07:46.703Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref network.connectivity-service.enabled to false
[task 2024-01-30T20:07:46.704Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref privacy.trackingprotection.enabled to false
[task 2024-01-30T20:07:46.705Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref security.fileuri.strict_origin_policy to false
[task 2024-01-30T20:07:46.705Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref signon.autofillForms to false
[task 2024-01-30T20:07:46.706Z] 20:07:46     INFO - STDOUT: 1706645266693	RemoteAgent	DEBUG	Setting recommended pref widget.windows.window_occlusion_tracking.enabled to false
[task 2024-01-30T20:07:46.707Z] 20:07:46     INFO - STDOUT: 1706645266694	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.features.standard to -tp,tpPrivate,cookieBehavior0,-cm,-fp
[task 2024-01-30T20:07:46.708Z] 20:07:46     INFO - STDOUT: 1706645266694	RemoteAgent	DEBUG	Setting recommended pref network.cookie.cookieBehavior to 0
[task 2024-01-30T20:07:46.708Z] 20:07:46     INFO - STDOUT: 1706645266694	CDP	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:46.877Z] 20:07:46     INFO - STDOUT: 1706645266882	RemoteAgent	INFO	Perform WebSocket upgrade for incoming connection from 127.0.0.1:52953
[task 2024-01-30T20:07:46.888Z] 20:07:46     INFO - STDOUT: [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2024-01-30T20:07:46.901Z] 20:07:46     INFO - STDOUT: 1706645266903	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 accepted
[task 2024-01-30T20:07:46.912Z] 20:07:46     INFO - STDOUT: 1706645266903	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 -> {"id":1,"method":"session.new","params":{"capabilities":{"alwaysMatch":{"moz:firefoxOptions":{"args":["--profile","C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmp816441wc.mozrunner"],"env":{"ALLUSERSPROFILE":"C:\\ProgramData","APPDATA":"Z:\\task_170664231575554\\AppData\\Roaming","COMMONPROGRAMFILES":"C:\\Program Files\\Common Files","COMMONPROGRAMFILES(X86)":"C:\\Program Files (x86)\\Common Files","COMMONPROGRAMW6432":"C:\\Program Files\\Common Files","COMPUTERNAME":"VM-RN8GLHSMRRAN","COMSPEC":"C:\\Windows\\system32\\cmd.exe","DRIVERDATA":"C:\\Windows\\System32\\Drivers\\DriverData","EXTRA_MOZHARNESS_CONFIG":"{\"installer_url\": \"https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build ... irefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build/target.test_packages.json\"}","GECKO_HEAD_REPOSITORY":"https://hg.mozilla.org/releases/mozilla-beta","GECKO_HEAD_REV":"814c511db3bf80ee923c7e26d7248df7690afbc7","HG_CACHE":"y:\\hg-cache","HOMEDRIVE":"C:","HOMEPATH":"\\Users\\task_170664231575554","LOCALAPPDATA":"C:\\Users\\task_170664231575554\\AppData\\Local","LOGONSERVER":"\\\\VM-RN8GLHSMRRAN","MOZHARNESS_TEST_PATHS":"{\"web-platform-tests-wdspec\": [\"/_mozilla/webdriver/bidi/browser/close\", \"/_mozilla/webdriver/bidi/browsing_context/set_viewp ... tests/classic/set_timeouts\", \"/webdriver/tests/classic/switch_to_frame\", \"/webdriver/tests/classic/take_element_screenshot\"]}","MOZILLABUILD":"C:\\mozilla-build","MOZ_AUTOMATION":"1","MOZ_FETCHES":"[{\"artifact\": \"public/build/fix-stacks.tar.zst\", \"extract\": true, \"task\": \"N10FEI3dTae7qF8CltO3-A\"}, {\"artifact\": \"public/bui ... SzWi80vEqzs81Q\"}, {\"artifact\": \"public/build/minidump-stackwalk.tar.zst\", \"extract\": true, \"task\": \"CJY1pIAgSAe9zquw6EUMhQ\"}]","MOZ_FETCHES_DIR":"Z:/task_170664231575554/fetches","MOZ_SCM_LEVEL":"3","NUMBER_OF_PROCESSORS":"8","OS":"Windows_NT","PATH":"Z:\\task_170664231575554\\build\\venv\\Scripts;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\Window ... 2\\usr\\bin;C:\\Users\\task_170664231575554\\AppData\\Local\\Microsoft\\WindowsApps;Z:\\task_170664231575554\\build\\application\\firefox","PATHEXT":".COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC","PIP_DOWNLOAD_CACHE":"y:\\pip-cache","PROCESSOR_ARCHITECTURE":"AMD64","PROCESSOR_IDENTIFIER":"Intel64 Family 6 Model 106 Stepping 6, GenuineIntel","PROCESSOR_LEVEL":"6","PROCE [... truncated after 2500 characters]
[task 2024-01-30T20:07:46.913Z] 20:07:46     INFO - STDOUT: 1706645266906	WebDriver BiDi	DEBUG	Connection 83f64262-04c0-4d95-9431-3398dc9d7d47 attached to session 685bbced-a0a2-4ec5-9b49-a0b8e0db4130
[task 2024-01-30T20:07:46.914Z] 20:07:46     INFO - STDOUT: 1706645266906	WebDriver BiDi	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:47.284Z] 20:07:47     INFO - STDOUT: console.error: ({})
[task 2024-01-30T20:07:47.331Z] 20:07:47     INFO - STDOUT: 1706645267333	RemoteAgent	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2024-01-30T20:07:47.338Z] 20:07:47     INFO - STDOUT: 1706645267337	WebDriver BiDi	DEBUG	Registered session handler: /session/685bbced-a0a2-4ec5-9b49-a0b8e0db4130
[task 2024-01-30T20:07:47.341Z] 20:07:47     INFO - STDOUT: 1706645267337	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 <- {"type":"success","id":1,"result":{"sessionId":"685bbced-a0a2-4ec5-9b49-a0b8e0db4130","capabilities":{"browserName":"firefox","browserVersion":"123.0","platformName":"windows","acceptInsecureCerts":false,"proxy":{},"setWindowRect":true,"moz:accessibilityChecks":false,"moz:buildID":"20240130172221","moz:headless":true,"moz:platformVersion":"10.0","moz:processID":3168,"moz:profile":"C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmpcvvpbrdx","moz:shutdownTimeout":60000,"moz:windowless":false}}}
[task 2024-01-30T20:07:47.342Z] 20:07:47     INFO - STDOUT: DevTools listening on ws://127.0.0.1:52952/devtools/browser/94b6578d-2f5d-42d8-9277-b585e7dfa559
[task 2024-01-30T20:07:47.342Z] 20:07:47     INFO - STDOUT: 1706645267338	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 -> {"id":2,"method":"browser.close","params":{}}
[task 2024-01-30T20:07:47.344Z] 20:07:47     INFO - STDOUT: 1706645267344	RemoteAgent	TRACE	Registered MessageHandlerFrame actors
[task 2024-01-30T20:07:47.347Z] 20:07:47     INFO - STDOUT: 1706645267346	RemoteAgent	TRACE	Created MessageHandler ROOT for session 685bbced-a0a2-4ec5-9b49-a0b8e0db4130
[task 2024-01-30T20:07:47.348Z] 20:07:47     INFO - STDOUT: 1706645267347	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:47.349Z] 20:07:47     INFO - STDOUT: 1706645267347	RemoteAgent	TRACE	Received command browser.close for destination ROOT
[task 2024-01-30T20:07:47.350Z] 20:07:47     INFO - STDOUT: 1706645267347	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:47.351Z] 20:07:47     INFO - STDOUT: 1706645267347	RemoteAgent	TRACE	Module root/browser.sys.mjs found for ROOT
[task 2024-01-30T20:07:47.352Z] 20:07:47     INFO - STDOUT: 1706645267347	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 <- {"type":"success","id":2,"result":{}}
[task 2024-01-30T20:07:47.353Z] 20:07:47     INFO - STDOUT: 1706645267347	WebDriver BiDi	DEBUG	Unregistered session handler: /session/685bbced-a0a2-4ec5-9b49-a0b8e0db4130
[task 2024-01-30T20:07:47.354Z] 20:07:47     INFO - STDOUT: 1706645267348	RemoteAgent	DEBUG	WebDriverBiDiConnection 83f64262-04c0-4d95-9431-3398dc9d7d47 closed
[task 2024-01-30T20:07:47.355Z] 20:07:47     INFO - STDOUT: 1706645267350	RemoteAgent	TRACE	MessageHandler ROOT for session 685bbced-a0a2-4ec5-9b49-a0b8e0db4130 is being destroyed
[task 2024-01-30T20:07:47.356Z] 20:07:47     INFO - STDOUT: 1706645267350	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session 685bbced-a0a2-4ec5-9b49-a0b8e0db4130
[task 2024-01-30T20:07:47.367Z] 20:07:47     INFO - STDOUT: 1706645267375	Marionette	TRACE	Received observer notification quit-application
[task 2024-01-30T20:07:47.378Z] 20:07:47     INFO - STDOUT: 1706645267375	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.introCount
[task 2024-01-30T20:07:47.379Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.search.update
[task 2024-01-30T20:07:47.380Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.closeWindowWithLastTab
[task 2024-01-30T20:07:47.381Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnClose
[task 2024-01-30T20:07:47.382Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2024-01-30T20:07:47.383Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.tabs.warnOnOpen
[task 2024-01-30T20:07:47.384Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref browser.usedOnWindows10.introURL
[task 2024-01-30T20:07:47.385Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2024-01-30T20:07:47.386Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref dom.navigation.locationChangeRateLimit.count
[task 2024-01-30T20:07:47.387Z] 20:07:47     INFO - STDOUT: 1706645267376	RemoteAgent	DEBUG	Resetting recommended pref dom.screenorientation.allow-lock
[task 2024-01-30T20:07:47.388Z] 20:07:47     INFO - STDOUT: 1706645267377	RemoteAgent	DEBUG	Resetting recommended pref network.connectivity-service.enabled
[task 2024-01-30T20:07:47.389Z] 20:07:47     INFO - STDOUT: 1706645267377	RemoteAgent	DEBUG	Resetting recommended pref privacy.trackingprotection.enabled
[task 2024-01-30T20:07:47.390Z] 20:07:47     INFO - STDOUT: 1706645267377	RemoteAgent	DEBUG	Resetting recommended pref security.fileuri.strict_origin_policy
[task 2024-01-30T20:07:47.391Z] 20:07:47     INFO - STDOUT: 1706645267377	RemoteAgent	DEBUG	Resetting recommended pref signon.autofillForms
[task 2024-01-30T20:07:47.392Z] 20:07:47     INFO - STDOUT: 1706645267378	RemoteAgent	DEBUG	Resetting recommended pref widget.windows.window_occlusion_tracking.enabled
[task 2024-01-30T20:07:47.392Z] 20:07:47     INFO - STDOUT: 1706645267378	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-30T20:07:47.393Z] 20:07:47     INFO - STDOUT: 1706645267378	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-30T20:07:47.394Z] 20:07:47     INFO - STDOUT: 1706645267381	RemoteAgent	TRACE	Received observer notification quit-application
[task 2024-01-30T20:07:47.405Z] 20:07:47     INFO - STDOUT: !!! error running onStopped callback: TypeError: callback is not a function
[task 2024-01-30T20:07:47.597Z] 20:07:47     INFO - STDOUT: 1706645267603	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2024-01-30T20:07:47.606Z] 20:07:47     INFO - STDOUT: 1706645267603	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2024-01-30T20:07:47.612Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.613Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.614Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.614Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.615Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.617Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.618Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.619Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.620Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.621Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.622Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.623Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.624Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.625Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.626Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.627Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.628Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.629Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.630Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.631Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.632Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.633Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.634Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.635Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.636Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.637Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.638Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.639Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.640Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.640Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.642Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.643Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.644Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.645Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.646Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.647Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.648Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.649Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.650Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.650Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.651Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.652Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.653Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.653Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.654Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.655Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/DeferredTask.sys.mjs, line 215: Error: Unable to arm timer, the object has been finalized.
[task 2024-01-30T20:07:47.691Z] 20:07:47     INFO - STDOUT: console.error: (new Error("IndexedDB: main/hijack-blocklists getLastModified() IndexedDB:  execute() The application is shutting down", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.702Z] 20:07:47     INFO - STDOUT: 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 2024-01-30T20:07:47.703Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: blocklists/gfx getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.704Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.706Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.707Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.707Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.709Z] 20:07:47     INFO - STDOUT: console.error: (new AbortError("IndexedDB: main/quicksuggest getLastModified() IndexedDB:  execute() A request was aborted, for example through a call to IDBTransaction.abort.", "resource://services-settings/IDBHelpers.sys.mjs", 16))
[task 2024-01-30T20:07:47.785Z] 20:07:47     INFO - STDOUT: console.error: (new TypeError("result[0] is undefined", "resource://gre/modules/Sqlite.sys.mjs", 1678))
[task 2024-01-30T20:07:47.796Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/Sqlite.sys.mjs, line 1678: TypeError: result[0] is undefined
[task 2024-01-30T20:07:47.796Z] 20:07:47     INFO - STDOUT: JavaScript error: resource://gre/modules/Sqlite.sys.mjs, line 1678: TypeError: result[0] is undefined
[task 2024-01-30T20:07:52.170Z] 20:07:52     INFO - STDOUT: *** You are running in headless mode.
[task 2024-01-30T20:07:52.295Z] 20:07:52     INFO - STDOUT: 1706645272302	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2024-01-30T20:07:52.305Z] 20:07:52     INFO - STDOUT: 1706645272302	RemoteAgent	DEBUG	CDP enabled
[task 2024-01-30T20:07:52.305Z] 20:07:52     INFO - STDOUT: 1706645272303	RemoteAgent	TRACE	Received observer notification final-ui-startup
[task 2024-01-30T20:07:52.316Z] 20:07:52     INFO - STDOUT: 1706645272322	RemoteAgent	TRACE	Available local IP addresses: 127.0.0.1, [::1]
[task 2024-01-30T20:07:52.326Z] 20:07:52     INFO - STDOUT: WebDriver BiDi listening on ws://127.0.0.1:52956
[task 2024-01-30T20:07:52.327Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.introCount to 99
[task 2024-01-30T20:07:52.327Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.search.update to false
[task 2024-01-30T20:07:52.328Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.closeWindowWithLastTab to false
[task 2024-01-30T20:07:52.329Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnClose to false
[task 2024-01-30T20:07:52.330Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
[task 2024-01-30T20:07:52.331Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.tabs.warnOnOpen to false
[task 2024-01-30T20:07:52.332Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref browser.usedOnWindows10.introURL to
[task 2024-01-30T20:07:52.333Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
[task 2024-01-30T20:07:52.334Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref dom.navigation.locationChangeRateLimit.count to 0
[task 2024-01-30T20:07:52.335Z] 20:07:52     INFO - STDOUT: 1706645272325	RemoteAgent	DEBUG	Setting recommended pref dom.screenorientation.allow-lock to true
[task 2024-01-30T20:07:52.336Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref network.connectivity-service.enabled to false
[task 2024-01-30T20:07:52.337Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref privacy.trackingprotection.enabled to false
[task 2024-01-30T20:07:52.337Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref security.fileuri.strict_origin_policy to false
[task 2024-01-30T20:07:52.338Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref signon.autofillForms to false
[task 2024-01-30T20:07:52.339Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref widget.windows.window_occlusion_tracking.enabled to false
[task 2024-01-30T20:07:52.339Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref browser.contentblocking.features.standard to -tp,tpPrivate,cookieBehavior0,-cm,-fp
[task 2024-01-30T20:07:52.340Z] 20:07:52     INFO - STDOUT: 1706645272326	RemoteAgent	DEBUG	Setting recommended pref network.cookie.cookieBehavior to 0
[task 2024-01-30T20:07:52.341Z] 20:07:52     INFO - STDOUT: 1706645272326	CDP	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:52.388Z] 20:07:52     INFO - STDOUT: 1706645272394	RemoteAgent	INFO	Perform WebSocket upgrade for incoming connection from 127.0.0.1:52957
[task 2024-01-30T20:07:52.419Z] 20:07:52     INFO - STDOUT: 1706645272417	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 accepted
[task 2024-01-30T20:07:52.428Z] 20:07:52     INFO - STDOUT: 1706645272418	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 -> {"id":1,"method":"session.new","params":{"capabilities":{"alwaysMatch":{"moz:firefoxOptions":{"args":["--profile","C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmp816441wc.mozrunner"],"env":{"ALLUSERSPROFILE":"C:\\ProgramData","APPDATA":"Z:\\task_170664231575554\\AppData\\Roaming","COMMONPROGRAMFILES":"C:\\Program Files\\Common Files","COMMONPROGRAMFILES(X86)":"C:\\Program Files (x86)\\Common Files","COMMONPROGRAMW6432":"C:\\Program Files\\Common Files","COMPUTERNAME":"VM-RN8GLHSMRRAN","COMSPEC":"C:\\Windows\\system32\\cmd.exe","DRIVERDATA":"C:\\Windows\\System32\\Drivers\\DriverData","EXTRA_MOZHARNESS_CONFIG":"{\"installer_url\": \"https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build ... irefox-ci-tc.services.mozilla.com/api/queue/v1/task/M-kYg-79Tlupb8S1UVwSzg/artifacts/public/build/target.test_packages.json\"}","GECKO_HEAD_REPOSITORY":"https://hg.mozilla.org/releases/mozilla-beta","GECKO_HEAD_REV":"814c511db3bf80ee923c7e26d7248df7690afbc7","HG_CACHE":"y:\\hg-cache","HOMEDRIVE":"C:","HOMEPATH":"\\Users\\task_170664231575554","LOCALAPPDATA":"C:\\Users\\task_170664231575554\\AppData\\Local","LOGONSERVER":"\\\\VM-RN8GLHSMRRAN","MOZHARNESS_TEST_PATHS":"{\"web-platform-tests-wdspec\": [\"/_mozilla/webdriver/bidi/browser/close\", \"/_mozilla/webdriver/bidi/browsing_context/set_viewp ... tests/classic/set_timeouts\", \"/webdriver/tests/classic/switch_to_frame\", \"/webdriver/tests/classic/take_element_screenshot\"]}","MOZILLABUILD":"C:\\mozilla-build","MOZ_AUTOMATION":"1","MOZ_FETCHES":"[{\"artifact\": \"public/build/fix-stacks.tar.zst\", \"extract\": true, \"task\": \"N10FEI3dTae7qF8CltO3-A\"}, {\"artifact\": \"public/bui ... SzWi80vEqzs81Q\"}, {\"artifact\": \"public/build/minidump-stackwalk.tar.zst\", \"extract\": true, \"task\": \"CJY1pIAgSAe9zquw6EUMhQ\"}]","MOZ_FETCHES_DIR":"Z:/task_170664231575554/fetches","MOZ_SCM_LEVEL":"3","NUMBER_OF_PROCESSORS":"8","OS":"Windows_NT","PATH":"Z:\\task_170664231575554\\build\\venv\\Scripts;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\Window ... 2\\usr\\bin;C:\\Users\\task_170664231575554\\AppData\\Local\\Microsoft\\WindowsApps;Z:\\task_170664231575554\\build\\application\\firefox","PATHEXT":".COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC","PIP_DOWNLOAD_CACHE":"y:\\pip-cache","PROCESSOR_ARCHITECTURE":"AMD64","PROCESSOR_IDENTIFIER":"Intel64 Family 6 Model 106 Stepping 6, GenuineIntel","PROCESSOR_LEVEL":"6","PROCE [... truncated after 2500 characters]
[task 2024-01-30T20:07:52.429Z] 20:07:52     INFO - STDOUT: 1706645272420	WebDriver BiDi	DEBUG	Connection c1972b3b-77a1-4d36-99a3-464423440f30 attached to session 34a9999e-a655-41a1-9661-4afd2fae0dde
[task 2024-01-30T20:07:52.430Z] 20:07:52     INFO - STDOUT: 1706645272420	WebDriver BiDi	DEBUG	Waiting for initial application window
[task 2024-01-30T20:07:52.538Z] 20:07:52     INFO - STDOUT: [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2024-01-30T20:07:52.937Z] 20:07:52     INFO - STDOUT: console.error: ({})
[task 2024-01-30T20:07:52.999Z] 20:07:52     INFO - STDOUT: 1706645273001	RemoteAgent	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2024-01-30T20:07:53.006Z] 20:07:53     INFO - STDOUT: 1706645273004	WebDriver BiDi	DEBUG	Registered session handler: /session/34a9999e-a655-41a1-9661-4afd2fae0dde
[task 2024-01-30T20:07:53.007Z] 20:07:53     INFO - STDOUT: PASSED
[task 2024-01-30T20:07:53.010Z] 20:07:53     INFO - STDOUT: 1706645273004	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 <- {"type":"success","id":1,"result":{"sessionId":"34a9999e-a655-41a1-9661-4afd2fae0dde","capabilities":{"browserName":"firefox","browserVersion":"123.0","platformName":"windows","acceptInsecureCerts":false,"proxy":{},"setWindowRect":true,"moz:accessibilityChecks":false,"moz:buildID":"20240130172221","moz:headless":true,"moz:platformVersion":"10.0","moz:processID":4176,"moz:profile":"C:\\Users\\task_170664231575554\\AppData\\Local\\Temp\\tmpzhq6jhb_","moz:shutdownTimeout":60000,"moz:windowless":false}}}
[task 2024-01-30T20:07:53.010Z] 20:07:53     INFO - STDOUT: DevTools listening on ws://127.0.0.1:52956/devtools/browser/afab50c4-467d-4914-bb90-5be3e56f06c6
[task 2024-01-30T20:07:53.011Z] 20:07:53     INFO - STDOUT: 1706645273007	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 -> {"id":2,"method":"session.end","params":{}}
[task 2024-01-30T20:07:53.014Z] 20:07:53     INFO - STDOUT: 1706645273013	RemoteAgent	TRACE	Registered MessageHandlerFrame actors
[task 2024-01-30T20:07:53.017Z] 20:07:53     INFO - STDOUT: 1706645273015	RemoteAgent	TRACE	Created MessageHandler ROOT for session 34a9999e-a655-41a1-9661-4afd2fae0dde
[task 2024-01-30T20:07:53.019Z] 20:07:53     INFO - STDOUT: 1706645273017	RemoteAgent	TRACE	Module root/session.sys.mjs found for ROOT
[task 2024-01-30T20:07:53.020Z] 20:07:53     INFO - STDOUT: 1706645273017	RemoteAgent	TRACE	Received command session.end for destination ROOT
[task 2024-01-30T20:07:53.021Z] 20:07:53     INFO - STDOUT: 1706645273017	RemoteAgent	TRACE	Module root/session.sys.mjs found for ROOT
[task 2024-01-30T20:07:53.022Z] 20:07:53     INFO - STDOUT: 1706645273017	RemoteAgent	TRACE	Module root/session.sys.mjs found for ROOT
[task 2024-01-30T20:07:53.023Z] 20:07:53     INFO - STDOUT: 1706645273018	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 <- {"type":"success","id":2,"result":{}}
[task 2024-01-30T20:07:53.024Z] 20:07:53     INFO - STDOUT: 1706645273018	WebDriver BiDi	DEBUG	Unregistered session handler: /session/34a9999e-a655-41a1-9661-4afd2fae0dde
[task 2024-01-30T20:07:53.025Z] 20:07:53     INFO - STDOUT: 1706645273018	RemoteAgent	DEBUG	WebDriverBiDiConnection c1972b3b-77a1-4d36-99a3-464423440f30 closed
[task 2024-01-30T20:07:53.026Z] 20:07:53     INFO - STDOUT: 1706645273020	RemoteAgent	TRACE	MessageHandler ROOT for session 34a9999e-a655-41a1-9661-4afd2fae0dde is being destroyed
[task 2024-01-30T20:07:53.027Z] 20:07:53     INFO - STDOUT: 1706645273020	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session 34a9999e-a655-41a1-9661-4afd2fae0dde
[task 2024-01-30T20:07:55.580Z] 20:07:55     INFO - TEST-UNEXPECTED-TIMEOUT | /_mozilla/webdriver/bidi/browser/close/close.py | expected OK
[task 2024-01-30T20:07:55.580Z] 20:07:55     INFO - TEST-INFO took 30020ms
[task 2024-01-30T20:07:55.583Z] 20:07:55     INFO - Restarting browser for new test group
[task 2024-01-30T20:07:56.268Z] 20:07:56     INFO - Closing logging queue
[task 2024-01-30T20:07:56.269Z] 20:07:56     INFO - queue closed
[task 2024-01-30T20:07:56.377Z] 20:07:56     INFO - PID 6540 | 1706645276284	geckodriver	INFO	Listening on 127.0.0.1:52961
[task 2024-01-30T20:07:56.380Z] 20:07:56     INFO - Starting runner
[task 2024-01-30T20:07:57.018Z] 20:07:57     INFO - TEST-START | /_mozilla/webdriver/bidi/browsing_context/set_viewport/invalid.py

This is caused by slow startup and shutdown times for Firefox.

Attachment #9386723 - Attachment is obsolete: true

Tier 1 failure here

Summary: Intermittent [tier 2] TEST-UNEXPECTED-TIMEOUT /_mozilla/webdriver/bidi/browser/close/close.py | single tracking bug → Intermittent TEST-UNEXPECTED-TIMEOUT /_mozilla/webdriver/bidi/browser/close/close.py | single tracking bug
Status: NEW → RESOLVED
Closed: 1 month ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

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

This is bug 1776189.

Status: REOPENED → RESOLVED
Closed: 1 month ago1 month ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: