Repository navigation
firefoxci-taskcluster / test-macosx1500-64-enterprise/debug-marionette-enterprise-1
succeeded
Aug 27, 2026 in 9m 8s
FirefoxCI (pull_request)
Marionette integration enterprise run (Treeherder job)
Details
View task in Taskcluster | View logs in Taskcluster | View task group in Taskcluster
Task Status
Started: 2026-08-27T21:19:08.835Z
Resolved: 2026-08-27T21:28:16.288Z
Task Execution Time: 9 minutes, 7 seconds, 453 milliseconds
Task Status: completed
Reason Resolved: completed
TaskId: RV2roJffSJG_Y3a8cltghw
RunId: 0
Artifacts
- public/build/perfherder-data-mozharness-actions.json
- public/fetch/perfherder-data-fetch-content.json
- public/logs/live_backing.log
- public/logs/live.log
- public/logs/localconfig.json
- public/test_info/marionette_errorsummary.log
- public/test_info/profile_resource-usage.json
- public/test_info/report.html
[taskcluster 2026-08-27T21:19:08.980Z] Worker Type (releng-hardware/gecko-t-osx-1500-m4) settings:
[taskcluster 2026-08-27T21:19:08.980Z] {
[taskcluster 2026-08-27T21:19:08.980Z] "arch": "arm64",
[taskcluster 2026-08-27T21:19:08.980Z] "config": {
[taskcluster 2026-08-27T21:19:08.980Z] "deploymentId": ""
[taskcluster 2026-08-27T21:19:08.980Z] },
[taskcluster 2026-08-27T21:19:08.980Z] "disk_size": "228.27 GiB",
[taskcluster 2026-08-27T21:19:08.980Z] "generic-worker": {
[taskcluster 2026-08-27T21:19:08.980Z] "config": {
[taskcluster 2026-08-27T21:19:08.980Z] "headlessTasks": false
[taskcluster 2026-08-27T21:19:08.980Z] },
[taskcluster 2026-08-27T21:19:08.980Z] "engine": "multiuser",
[taskcluster 2026-08-27T21:19:08.980Z] "go-arch": "arm64",
[taskcluster 2026-08-27T21:19:08.980Z] "go-os": "darwin",
[taskcluster 2026-08-27T21:19:08.980Z] "go-version": "go1.25.3",
[taskcluster 2026-08-27T21:19:08.980Z] "release": "https://github.com/taskcluster/taskcluster/releases/tag/v91.0.2",
[taskcluster 2026-08-27T21:19:08.980Z] "revision": "06628b37211e56a8bd044bf879260bc792c4fa4a",
[taskcluster 2026-08-27T21:19:08.980Z] "source": "https://github.com/taskcluster/taskcluster/commits/06628b37211e56a8bd044bf879260bc792c4fa4a",
[taskcluster 2026-08-27T21:19:08.980Z] "version": "91.0.2"
[taskcluster 2026-08-27T21:19:08.980Z] },
...(33121 lines hidden)...
[task 2026-08-27T21:28:12.608+00:00] 21:28:12 INFO - GL_VENDOR: Apple
[task 2026-08-27T21:28:12.608+00:00] 21:28:12 INFO - mVendor: Unknown
[task 2026-08-27T21:28:12.608+00:00] 21:28:12 INFO - GL_RENDERER: Apple M4
[task 2026-08-27T21:28:12.608+00:00] 21:28:12 INFO - mRenderer: Unknown
[task 2026-08-27T21:28:12.608+00:00] 21:28:12 INFO - mIsMesa: 0
[task 2026-08-27T21:28:12.705+00:00] 21:28:12 INFO - [Parent 4139, GMPThread] WARNING: Failed to delete GMP storage directory: file checkouts/gecko/dom/media/gmp/GMPServiceParent.cpp:1947
[task 2026-08-27T21:28:12.730+00:00] 21:28:12 INFO - 1787866092729 Marionette TRACE Received observer notification final-ui-startup
[task 2026-08-27T21:28:12.730+00:00] 21:28:12 INFO - 1787866092730 Marionette DEBUG Initializing Marionette
[task 2026-08-27T21:28:12.735+00:00] 21:28:12 INFO - [Parent 4139, Main Thread] WARNING: 'mIndex >= Count()', file checkouts/gecko/xpcom/ds/nsStringEnumerator.cpp:200
[task 2026-08-27T21:28:12.735+00:00] 21:28:12 INFO - [Parent 4139, Main Thread] WARNING: 'mIndex >= Count()', file checkouts/gecko/xpcom/ds/nsStringEnumerator.cpp:200
[task 2026-08-27T21:28:12.735+00:00] 21:28:12 INFO - [Parent 4139, Main Thread] WARNING: 'mIndex >= Count()', file checkouts/gecko/xpcom/ds/nsStringEnumerator.cpp:200
[task 2026-08-27T21:28:12.811+00:00] 21:28:12 INFO - 1787866092811 Marionette INFO Listening on port 2828
[task 2026-08-27T21:28:12.812+00:00] 21:28:12 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: storage/permanent/chrome/idb/3561288849sdhlie.sqlite
[task 2026-08-27T21:28:12.812+00:00] 21:28:12 INFO - 1787866092812 Marionette DEBUG Marionette is listening
[task 2026-08-27T21:28:12.814+00:00] 21:28:12 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: bounce-tracking-protection.sqlite
[task 2026-08-27T21:28:12.830+00:00] 21:28:12 INFO - 1787866092830 Marionette DEBUG Accepted connection 0 from 127.0.0.1:51979
[task 2026-08-27T21:28:12.854+00:00] 21:28:12 INFO - 1787866092854 Marionette DEBUG Closed connection 0
[task 2026-08-27T21:28:12.854+00:00] 21:28:12 INFO - 1787866092854 Marionette DEBUG Accepted connection 1 from 127.0.0.1:51980
[task 2026-08-27T21:28:12.919+00:00] 21:28:12 INFO - 1787866092919 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2026-08-27T21:28:12.923+00:00] 21:28:12 INFO - 1787866092923 Marionette DEBUG Waiting for initial application window
[task 2026-08-27T21:28:13.181+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: '!anonymousDivElement', file checkouts/gecko/dom/html/TextControlState.cpp:1626
[task 2026-08-27T21:28:13.181+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(PrepareEditor()) failed with result 0x80004005 (NS_ERROR_FAILURE): file checkouts/gecko/dom/html/TextControlState.cpp:1863
[task 2026-08-27T21:28:13.188+00:00] 21:28:13 INFO - [Child 4143, Main Thread] WARNING: 'NS_FAILED(rv)', file checkouts/gecko/modules/libjar/nsJARChannel.cpp:388
[task 2026-08-27T21:28:13.274+00:00] 21:28:13 INFO - UNSUPPORTED (log once): POSSIBLE ISSUE: unit 1 GLD_TEXTURE_INDEX_2D is unloadable and bound to sampler type (Float) - using zero texture because texture unloadable
[task 2026-08-27T21:28:13.275+00:00] 21:28:13 INFO - [WARN webrender::device::gl] Missing optimized shader source for ps_quad_gradient_DITHERING
[task 2026-08-27T21:28:13.291+00:00] 21:28:13 INFO - 2026-08-27 21:28:13.291 firefox[4139:60705] +[IMKClient subclass]: chose IMKClient_Modern
[task 2026-08-27T21:28:13.327+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: Ignoring duplicate observer: ui.new-webcompat-reporter.screenshots.enabled: file checkouts/gecko/modules/libpref/Preferences.cpp:3498
[task 2026-08-27T21:28:13.327+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: Ignoring duplicate observer: ui.new-webcompat-reporter.show-send-more-info-link: file checkouts/gecko/modules/libpref/Preferences.cpp:3498
[task 2026-08-27T21:28:13.362+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: 33d9f1ec.sqlite
[task 2026-08-27T21:28:13.416+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: storage/permanent/chrome/idb/1451318868ntouromlalnodry--epcr.sqlite
[task 2026-08-27T21:28:13.461+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: content-prefs.sqlite
[task 2026-08-27T21:28:13.469+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: logins.db
[task 2026-08-27T21:28:13.486+00:00] 21:28:13 INFO - [Parent 4139, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001 (NS_ERROR_STORAGE_BUSY): file /builds/worker/checkouts/gecko/storage/mozStorageConnection.cpp:1358
[task 2026-08-27T21:28:13.487+00:00] 21:28:13 INFO - [Parent 4139, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001 (NS_ERROR_STORAGE_BUSY): file checkouts/gecko/storage/mozStorageService.cpp:653
[task 2026-08-27T21:28:13.487+00:00] 21:28:13 INFO - [Parent 4139, QuotaManager IO] WARNING: QM_TRY failure (ERROR): '::mozilla::ToResultInvoke< nsCOMPtr<mozIStorageConnection>>( ::std::mem_fn( &::mozilla::detail::DerefedType<decltype(aStorageService)>::OpenDatabaseWithFileURL), (aStorageService), &aFileURL, telemetryFilename, mozIStorageService::CONNECTION_INTERRUPTIBLE) failed with resultCode 0x80630001, resultName NS_ERROR_STORAGE_BUSY', file ActorsParent.cpp:707
[task 2026-08-27T21:28:13.487+00:00] 21:28:13 INFO - [Parent 4139, QuotaManager IO] WARNING: QM_TRY failure (WARNING): '"OpenDatabase(aStorageService, aFileURL, aTelemetryId) .map([](auto connection) -> ConnectionType { return Some(std::move(connection)); })" failed with resultCode 0x80630001, resultName NS_ERROR_STORAGE_BUSY', file ActorsParent.cpp:731
[task 2026-08-27T21:28:13.487+00:00] 21:28:13 INFO - [Parent 4139, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3870112724rsegmnoittet-es.sqlite', retrying for up to 10 seconds: file /builds/worker/checkouts/gecko/dom/indexedDB/ActorsParent.cpp:743
[task 2026-08-27T21:28:13.617+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: places.sqlite
[task 2026-08-27T21:28:13.618+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: favicons.sqlite
[task 2026-08-27T21:28:13.671+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1227
[task 2026-08-27T21:28:13.686+00:00] 21:28:13 INFO - console.error: RSLoader:
[task 2026-08-27T21:28:13.686+00:00] 21:28:13 INFO - Failed to retrieve recipes from Remote Settings
[task 2026-08-27T21:28:13.686+00:00] 21:28:13 INFO - Message: Error: Could not sync nimbus-desktop-experiments: get-exception
[task 2026-08-27T21:28:13.687+00:00] 21:28:13 INFO - Stack:
[task 2026-08-27T21:28:13.687+00:00] 21:28:13 INFO - RemoteSettingsSyncError@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:1426:5
[task 2026-08-27T21:28:13.687+00:00] 21:28:13 INFO - getRecipesFromCollection@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:698:13
[task 2026-08-27T21:28:13.696+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: NS_ENSURE_TRUE(mNameHashtable.Get(aName, &index)) failed: file checkouts/gecko/storage/mozStorageRow.cpp:89
[task 2026-08-27T21:28:13.697+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: storage/permanent/chrome/idb/2823318777ntouromlalnodry--naod.sqlite
[task 2026-08-27T21:28:13.706+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: 'mIndex >= Count()', file checkouts/gecko/xpcom/ds/nsStringEnumerator.cpp:200
[task 2026-08-27T21:28:13.706+00:00] 21:28:13 INFO - [Parent 4139, Main Thread] WARNING: 'mIndex >= Count()', file checkouts/gecko/xpcom/ds/nsStringEnumerator.cpp:200
[task 2026-08-27T21:28:13.935+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: storage/permanent/chrome/idb/1974846527meornoittso-r.sqlite
[task 2026-08-27T21:28:13.939+00:00] 21:28:13 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: domain_to_categories.sqlite
[task 2026-08-27T21:28:14.097+00:00] 21:28:14 INFO - [ERROR lockstore_ffi] Lockstore error: Key not found: DEK not found for dek_name: storage/permanent/chrome/idb/1657114595AmcateirvtiSty.sqlite
[task 2026-08-27T21:28:14.268+00:00] 21:28:14 INFO - 1787866094267 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2026-08-27T21:28:14.374+00:00] 21:28:14 INFO - 1787866094374 RemoteAgent TRACE [11] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2026-08-27T21:28:14.375+00:00] 21:28:14 INFO - 1787866094374 RemoteAgent TRACE [11] ProgressListener Setting unload timer (40000ms)
[task 2026-08-27T21:28:14.375+00:00] 21:28:14 INFO - 1787866094375 RemoteAgent TRACE [11] Wait for initial navigation: isUncommittedInitial=false, isLoadingDocument=false
[task 2026-08-27T21:28:14.375+00:00] 21:28:14 INFO - 1787866094375 RemoteAgent TRACE [11] Document already finished loading: about:blank
[task 2026-08-27T21:28:14.375+00:00] 21:28:14 INFO - 1787866094375 RemoteAgent TRACE [11] ProgressListener Stop: has error=false url=about:blank
[task 2026-08-27T21:28:14.383+00:00] 21:28:14 INFO - 1787866094383 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"d3f41e1f-3aed-469d-8f70-69883dcdafb5","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"156.0a1","platformName":"mac","setWindowRect":true,"unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:156.0) Gecko/20100101 Firefox/156.0","moz:buildID":"20260827203810","moz:headless":false,"moz:platformVersion":"24.3.0","moz:processID":4139,"moz:profile":"/tmp/tmpxye4ycpk.mozrunner","moz:shutdownTimeout":60000,"moz:browserFlavor":"enterprise","pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2026-08-27T21:28:14.386+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1533
[task 2026-08-27T21:28:14.386+00:00] 21:28:14 INFO - 1787866094386 Marionette DEBUG 1 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2026-08-27T21:28:14.387+00:00] 21:28:14 INFO - 1787866094387 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2026-08-27T21:28:14.387+00:00] 21:28:14 INFO - 1787866094387 Marionette DEBUG 1 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2026-08-27T21:28:14.387+00:00] 21:28:14 INFO - 1787866094387 Marionette DEBUG 1 <- [1,3,null,{"value":null}]
[task 2026-08-27T21:28:14.388+00:00] 21:28:14 INFO - 1787866094388 Marionette DEBUG 1 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2026-08-27T21:28:14.388+00:00] 21:28:14 INFO - 1787866094388 Marionette DEBUG 1 <- [1,4,null,{"value":null}]
[task 2026-08-27T21:28:14.388+00:00] 21:28:14 INFO - Marionette ready
[task 2026-08-27T21:28:14.389+00:00] 21:28:14 INFO - 1787866094389 Marionette DEBUG 1 -> [0,5,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2026-08-27T21:28:14.395+00:00] 21:28:14 INFO - 1787866094395 RemoteAgent TRACE Received DOM event TabOpen for [object XULElement]
[task 2026-08-27T21:28:14.423+00:00] 21:28:14 INFO - 1787866094423 RemoteAgent TRACE Received DOM event TabSelect for [object XULElement]
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 RemoteAgent TRACE [13] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 RemoteAgent TRACE [13] ProgressListener Setting unload timer (40000ms)
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 RemoteAgent TRACE [13] Wait for initial navigation: isUncommittedInitial=false, isLoadingDocument=false
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 RemoteAgent TRACE [13] Document already finished loading: about:blank
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 RemoteAgent TRACE [13] ProgressListener Stop: has error=false url=about:blank
[task 2026-08-27T21:28:14.429+00:00] 21:28:14 INFO - 1787866094429 Marionette DEBUG 1 <- [1,5,null,{"handle":"94a3586a-5cd6-442e-9066-0ac61836faa8","type":"tab"}]
[task 2026-08-27T21:28:14.434+00:00] 21:28:14 INFO - 1787866094434 Marionette DEBUG 1 -> [0,6,"WebDriver:SwitchToWindow",{"handle":"94a3586a-5cd6-442e-9066-0ac61836faa8","focus":true}]
[task 2026-08-27T21:28:14.438+00:00] 21:28:14 INFO - 1787866094438 RemoteAgent TRACE Received DOM event TabSelect for [object XULElement]
[task 2026-08-27T21:28:14.444+00:00] 21:28:14 INFO - 1787866094444 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2026-08-27T21:28:14.446+00:00] 21:28:14 INFO - 1787866094446 Marionette DEBUG 1 -> [0,7,"WebDriver:Navigate",{"url":"about:support"}]
[task 2026-08-27T21:28:14.450+00:00] 21:28:14 INFO - 1787866094450 Marionette TRACE [13] Received event beforeunload for about:blank
[task 2026-08-27T21:28:14.459+00:00] 21:28:14 INFO - 1787866094459 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 14
[task 2026-08-27T21:28:14.460+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file checkouts/gecko/dom/base/Document.cpp:18198
[task 2026-08-27T21:28:14.469+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: 'aOwner->IsDiscarded()', file /builds/worker/workspace/obj-build/dist/include/mozilla/dom/SyncedContextInlines.h:93
[task 2026-08-27T21:28:14.473+00:00] 21:28:14 INFO - 1787866094473 Marionette TRACE [14] Received event beforeunload for about:blank
[task 2026-08-27T21:28:14.473+00:00] 21:28:14 INFO - 1787866094473 Marionette TRACE [14] Received event pagehide for about:blank
[task 2026-08-27T21:28:14.612+00:00] 21:28:14 INFO - JavaScript warning: resource://gre/modules/Troubleshoot.sys.mjs, line 768: WebGL context was lost.
[task 2026-08-27T21:28:14.622+00:00] 21:28:14 INFO - JavaScript warning: resource://gre/modules/Troubleshoot.sys.mjs, line 768: WebGL context was lost.
[task 2026-08-27T21:28:14.675+00:00] 21:28:14 INFO - 1787866094675 Marionette TRACE [14] Received event DOMContentLoaded for about:support
[task 2026-08-27T21:28:14.685+00:00] 21:28:14 INFO - 1787866094685 Marionette TRACE [14] Received event pageshow for about:support
[task 2026-08-27T21:28:14.685+00:00] 21:28:14 INFO - 1787866094685 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2026-08-27T21:28:14.689+00:00] 21:28:14 INFO - [WARN wgpu_bindings::server] No suitable graphics adapter found; noop not requested, vulkan support not compiled in, metal had no fallback adapters, dx12 support not compiled in, gl not requested, webgpu support not compiled in
[task 2026-08-27T21:28:14.691+00:00] 21:28:14 INFO - 1787866094690 Marionette DEBUG 1 -> [0,8,"WebDriver:FindElement",{"value":"version-box","using":"id"}]
[task 2026-08-27T21:28:14.694+00:00] 21:28:14 INFO - 1787866094694 RemoteAgent TRACE WebDriverProcessData actor created for PID 4139
[task 2026-08-27T21:28:14.694+00:00] 21:28:14 INFO - 1787866094694 Marionette TRACE [14] MarionetteCommands actor created for window id 29
[task 2026-08-27T21:28:14.697+00:00] 21:28:14 INFO - 1787866094696 Marionette DEBUG 1 <- [1,8,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"968abccf-6054-4d15-8ee1-fa2859964a87"}}]
[task 2026-08-27T21:28:14.697+00:00] 21:28:14 INFO - 1787866094697 Marionette DEBUG 1 -> [0,9,"WebDriver:IsElementDisplayed",{"id":"968abccf-6054-4d15-8ee1-fa2859964a87"}]
[task 2026-08-27T21:28:14.710+00:00] 21:28:14 INFO - 1787866094710 Marionette DEBUG 1 <- [1,9,null,{"value":true}]
[task 2026-08-27T21:28:14.711+00:00] 21:28:14 INFO - 1787866094711 Marionette DEBUG 1 -> [0,10,"WebDriver:GetElementText",{"id":"968abccf-6054-4d15-8ee1-fa2859964a87"}]
[task 2026-08-27T21:28:14.717+00:00] 21:28:14 INFO - 1787866094717 Marionette DEBUG 1 <- [1,10,null,{"value":""}]
[task 2026-08-27T21:28:14.717+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: 'NS_FAILED(rv)', file checkouts/gecko/dom/console/ConsoleInstance.cpp:111
[task 2026-08-27T21:28:14.717+00:00] 21:28:14 INFO - console.info: MachineId: "Using \"ioplatform-serial\" as machine ID source"
[task 2026-08-27T21:28:14.814+00:00] 21:28:14 INFO - 1787866094813 Marionette DEBUG 1 -> [0,11,"WebDriver:GetElementText",{"id":"968abccf-6054-4d15-8ee1-fa2859964a87"}]
[task 2026-08-27T21:28:14.820+00:00] 21:28:14 INFO - 1787866094820 Marionette DEBUG 1 <- [1,11,null,{"value":"156.0a1"}]
[task 2026-08-27T21:28:14.821+00:00] 21:28:14 INFO - 1787866094821 Marionette DEBUG 1 -> [0,12,"WebDriver:GetElementText",{"id":"968abccf-6054-4d15-8ee1-fa2859964a87"}]
[task 2026-08-27T21:28:14.826+00:00] 21:28:14 INFO - 1787866094826 Marionette DEBUG 1 <- [1,12,null,{"value":"156.0a1"}]
[task 2026-08-27T21:28:14.826+00:00] 21:28:14 INFO - about:support version: 156.0a1
[task 2026-08-27T21:28:14.826+00:00] 21:28:14 INFO - 1787866094826 Marionette DEBUG 1 -> [0,13,"WebDriver:ExecuteScript",{"script":"const { AppConstants } = ChromeUtils.importESModule('resource://gre/modules/AppConstants.sys.mjs'); return AppConstants.MOZ_APP_VERSION_DISPLAY;","args":[],"newSandbox":true,"sandbox":"default","line":30,"filename":"tests/testing/enterprise/test_firefox_start.py"}]
[task 2026-08-27T21:28:14.828+00:00] 21:28:14 INFO - 1787866094828 Marionette DEBUG 1 <- [1,13,null,{"value":"156.0a1"}]
[task 2026-08-27T21:28:14.828+00:00] 21:28:14 INFO - expected version: 156.0a1
[task 2026-08-27T21:28:14.828+00:00] 21:28:14 INFO - 1787866094828 Marionette DEBUG 1 -> [0,14,"WebDriver:GetElementText",{"id":"968abccf-6054-4d15-8ee1-fa2859964a87"}]
[task 2026-08-27T21:28:14.833+00:00] 21:28:14 INFO - 1787866094833 Marionette DEBUG 1 <- [1,14,null,{"value":"156.0a1"}]
[task 2026-08-27T21:28:14.833+00:00] 21:28:14 INFO - 1787866094833 Marionette DEBUG 1 -> [0,15,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2026-08-27T21:28:14.837+00:00] 21:28:14 INFO - 1787866094837 RemoteAgent TRACE Received DOM event TabOpen for [object XULElement]
[task 2026-08-27T21:28:14.854+00:00] 21:28:14 INFO - 1787866094854 RemoteAgent TRACE Received DOM event TabSelect for [object XULElement]
[task 2026-08-27T21:28:14.858+00:00] 21:28:14 INFO - 1787866094858 RemoteAgent TRACE [15] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2026-08-27T21:28:14.858+00:00] 21:28:14 INFO - 1787866094858 RemoteAgent TRACE [15] ProgressListener Setting unload timer (40000ms)
[task 2026-08-27T21:28:14.858+00:00] 21:28:14 INFO - 1787866094858 RemoteAgent TRACE [15] Wait for initial navigation: isUncommittedInitial=false, isLoadingDocument=false
[task 2026-08-27T21:28:14.858+00:00] 21:28:14 INFO - 1787866094858 RemoteAgent TRACE [15] Document already finished loading: about:blank
[task 2026-08-27T21:28:14.858+00:00] 21:28:14 INFO - 1787866094858 RemoteAgent TRACE [15] ProgressListener Stop: has error=false url=about:blank
[task 2026-08-27T21:28:14.859+00:00] 21:28:14 INFO - 1787866094858 Marionette DEBUG 1 <- [1,15,null,{"handle":"6b437dda-3ec7-42a2-a143-ddc54dd4731c","type":"tab"}]
[task 2026-08-27T21:28:14.860+00:00] 21:28:14 INFO - 1787866094860 Marionette DEBUG 1 -> [0,16,"WebDriver:SwitchToWindow",{"handle":"6b437dda-3ec7-42a2-a143-ddc54dd4731c","focus":true}]
[task 2026-08-27T21:28:14.863+00:00] 21:28:14 INFO - 1787866094863 RemoteAgent TRACE Received DOM event TabSelect for [object XULElement]
[task 2026-08-27T21:28:14.873+00:00] 21:28:14 INFO - 1787866094873 Marionette DEBUG 1 <- [1,16,null,{"value":null}]
[task 2026-08-27T21:28:14.875+00:00] 21:28:14 INFO - 1787866094875 Marionette DEBUG 1 -> [0,17,"WebDriver:Navigate",{"url":"about:buildconfig"}]
[task 2026-08-27T21:28:14.876+00:00] 21:28:14 INFO - 1787866094876 Marionette TRACE [15] Received event beforeunload for about:blank
[task 2026-08-27T21:28:14.879+00:00] 21:28:14 INFO - 1787866094879 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 16
[task 2026-08-27T21:28:14.886+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1227
[task 2026-08-27T21:28:14.886+00:00] 21:28:14 INFO - [Parent 4139, Main Thread] WARNING: 'aOwner->IsDiscarded()', file /builds/worker/workspace/obj-build/dist/include/mozilla/dom/SyncedContextInlines.h:93
[task 2026-08-27T21:28:14.891+00:00] 21:28:14 INFO - 1787866094891 Marionette TRACE [16] Received event beforeunload for about:blank
[task 2026-08-27T21:28:14.891+00:00] 21:28:14 INFO - 1787866094891 Marionette TRACE [16] Received event pagehide for about:blank
[task 2026-08-27T21:28:14.898+00:00] 21:28:14 INFO - 1787866094898 Marionette TRACE [16] Received event DOMContentLoaded for about:buildconfig
[task 2026-08-27T21:28:14.903+00:00] 21:28:14 INFO - 1787866094903 Marionette TRACE [16] Received event pageshow for about:buildconfig
[task 2026-08-27T21:28:14.903+00:00] 21:28:14 INFO - 1787866094903 Marionette DEBUG 1 <- [1,17,null,{"value":null}]
[task 2026-08-27T21:28:14.905+00:00] 21:28:14 INFO - 1787866094904 Marionette DEBUG 1 -> [0,18,"WebDriver:FindElement",{"value":"p:last-child","using":"css selector"}]
[task 2026-08-27T21:28:14.905+00:00] 21:28:14 INFO - 1787866094905 Marionette TRACE [16] MarionetteCommands actor created for window id 34
[task 2026-08-27T21:28:14.905+00:00] 21:28:14 INFO - 1787866094905 Marionette DEBUG 1 <- [1,18,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"78d1525a-d635-409d-a4e0-892577fb9e37"}}]
[task 2026-08-27T21:28:14.906+00:00] 21:28:14 INFO - 1787866094906 Marionette DEBUG 1 -> [0,19,"WebDriver:IsElementDisplayed",{"id":"78d1525a-d635-409d-a4e0-892577fb9e37"}]
[task 2026-08-27T21:28:14.917+00:00] 21:28:14 INFO - 1787866094917 Marionette DEBUG 1 <- [1,19,null,{"value":true}]
[task 2026-08-27T21:28:14.918+00:00] 21:28:14 INFO - 1787866094918 Marionette DEBUG 1 -> [0,20,"WebDriver:GetElementText",{"id":"78d1525a-d635-409d-a4e0-892577fb9e37"}]
[task 2026-08-27T21:28:14.923+00:00] 21:28:14 INFO - 1787866094923 Marionette DEBUG 1 <- [1,20,null,{"value":"MOZ_AUTOMATION=1 --target=aarch64-apple-darwin MOZILLA_OFFICIAL=1 MOZBUILD_STATE_PATH=/builds/worker/.mozbuild --enable-debug ... rise-nightly --enable-enterprise MKFSHFS=/builds/worker/fetches/hfsplus/newfs_hfs HFS_TOOL=/builds/worker/fetches/dmg/hfsplus"}]
[task 2026-08-27T21:28:14.924+00:00] 21:28:14 INFO - 1787866094923 Marionette DEBUG 1 -> [0,21,"WebDriver:GetElementText",{"id":"78d1525a-d635-409d-a4e0-892577fb9e37"}]
[task 2026-08-27T21:28:14.928+00:00] 21:28:14 INFO - 1787866094928 Marionette DEBUG 1 <- [1,21,null,{"value":"MOZ_AUTOMATION=1 --target=aarch64-apple-darwin MOZILLA_OFFICIAL=1 MOZBUILD_STATE_PATH=/builds/worker/.mozbuild --enable-debug ... rise-nightly --enable-enterprise MKFSHFS=/builds/worker/fetches/hfsplus/newfs_hfs HFS_TOOL=/builds/worker/fetches/dmg/hfsplus"}]
[task 2026-08-27T21:28:14.928+00:00] 21:28:14 INFO - about:buildconfig buildflags: MOZ_AUTOMATION=1 --target=aarch64-apple-darwin MOZILLA_OFFICIAL=1 MOZBUILD_STATE_PATH=/builds/worker/.mozbuild --enable-debug MOZ_FETCHES_DIR=/builds/worker/fetches HOST_CFLAGS=-g HOST_CXXFLAGS=-g HOST_LDFLAGS=-g 'CFLAGS= -fcrash-diagnostics-dir=/builds/worker/artifacts' 'CXXFLAGS= -fcrash-diagnostics-dir=/builds/worker/artifacts' CCACHE=sccache SCCACHE_VERBOSE_STATS=1 --enable-clang-plugin MOZ_SOURCE_REPO=https://github.com/1rneh/enterprise-firefox MOZ_SOURCE_CHANGESET=93d3353e1d1f1f22e1c119a807a4d670c3713e6a --enable-js-shell --enable-rust-simd MOZ_SIMPLE_PACKAGE_NAME=target DMG_TOOL=/builds/worker/fetches/dmg/dmg MAR_CHANNEL_ID=firefox-enterprise-nightly ACCEPTED_MAR_CHANNEL_IDS=firefox-enterprise-nightly --enable-enterprise MKFSHFS=/builds/worker/fetches/hfsplus/newfs_hfs HFS_TOOL=/builds/worker/fetches/dmg/hfsplus
[task 2026-08-27T21:28:14.928+00:00] 21:28:14 INFO - 1787866094928 Marionette DEBUG 1 -> [0,22,"WebDriver:GetElementText",{"id":"78d1525a-d635-409d-a4e0-892577fb9e37"}]
[task 2026-08-27T21:28:14.935+00:00] 21:28:14 INFO - 1787866094934 Marionette DEBUG 1 <- [1,22,null,{"value":"MOZ_AUTOMATION=1 --target=aarch64-apple-darwin MOZILLA_OFFICIAL=1 MOZBUILD_STATE_PATH=/builds/worker/.mozbuild --enable-debug ... rise-nightly --enable-enterprise MKFSHFS=/builds/worker/fetches/hfsplus/newfs_hfs HFS_TOOL=/builds/worker/fetches/dmg/hfsplus"}]
[task 2026-08-27T21:28:14.943+00:00] 21:28:14 INFO - 1787866094936 Marionette TRACE [14] MarionetteCommands actor destroyed for window id 29
[task 2026-08-27T21:28:14.943+00:00] 21:28:14 INFO - 1787866094936 Marionette TRACE [16] MarionetteCommands actor destroyed for window id 34
[task 2026-08-27T21:28:14.943+00:00] 21:28:14 INFO - 1787866094936 Marionette DEBUG Closed connection 1
[task 2026-08-27T21:28:14.983+00:00] 21:28:14 INFO - TEST-PASS | testing/enterprise/test_firefox_start.py EnterpriseTests.test_firefox_start | took 2973ms
[task 2026-08-27T21:28:14.983+00:00] 21:28:14 INFO -
[task 2026-08-27T21:28:14.983+00:00] 21:28:14 INFO - SUMMARY
[task 2026-08-27T21:28:14.983+00:00] 21:28:14 INFO - -------
[task 2026-08-27T21:28:14.983+00:00] 21:28:14 INFO - passed: 52
[task 2026-08-27T21:28:14.984+00:00] 21:28:14 INFO - failed: 0
[task 2026-08-27T21:28:14.984+00:00] 21:28:14 INFO - todo: 2
[task 2026-08-27T21:28:14.984+00:00] 21:28:14 INFO - SUITE-END | took 481s
[task 2026-08-27T21:28:15.030+00:00] 21:28:15 INFO - /Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/multiprocessing/resource_tracker.py:224: UserWarning: resource_tracker: There appear to be 204 leaked semaphore objects to clean up at shutdown
[task 2026-08-27T21:28:15.030+00:00] 21:28:15 INFO - warnings.warn('resource_tracker: There appear to be %d '
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Return code: 0
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - TinderboxPrint: marionette<br/>54/0/0
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - gecko.log not found
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - TinderboxPrint: marionette<br/>54/0/0
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Marionette exited with return code 0: SUCCESS
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Running post-action listener: _package_coverage_data
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Running post-action listener: _resource_record_post_action
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Running post-action listener: process_java_coverage_data
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - [mozharness: 2026-08-27 21:28:15.033447Z] Finished run-tests step (success)
[task 2026-08-27T21:28:15.033+00:00] 21:28:15 INFO - Running post-run listener: _resource_record_post_run
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - Total resource usage - Wall time: 499s; CPU: 24%; Read bytes: 1344409600; Write bytes: 5528985600; Read time: 27006; Write time: 5896
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: CPU usage<br/>23.6%
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: I/O read bytes / time<br/>1,344,409,600 / 27,006
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: I/O write bytes / time<br/>5,528,985,600 / 5,896
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: CPU idle<br/>3,791.3 (76.3%)
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: CPU system<br/>270.1 (5.4%)
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: CPU user<br/>908.6 (18.3%)
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - TinderboxPrint: Swap in / out<br/>1,104,019,456 / 360,448
[task 2026-08-27T21:28:15.066+00:00] 21:28:15 INFO - install - Wall time: 14s; CPU: 21%; Read bytes: 584760320; Write bytes: 472444928; Read time: 15865; Write time: 515
[task 2026-08-27T21:28:15.076+00:00] 21:28:15 INFO - run-tests - Wall time: 485s; CPU: 24%; Read bytes: 1217921024; Write bytes: 5054750720; Read time: 23368; Write time: 5375
[taskcluster 2026-08-27T21:28:15.272Z] Exit Code: 0
[taskcluster 2026-08-27T21:28:15.272Z] User Time: 8m49.769968s
[taskcluster 2026-08-27T21:28:15.272Z] Kernel Time: 1m16.56723s
[taskcluster 2026-08-27T21:28:15.272Z] Wall Time: 9m0.414789s
[taskcluster 2026-08-27T21:28:15.272Z] Average Available System Memory: 7.91 GiB
[taskcluster 2026-08-27T21:28:15.272Z] Average System Memory Used: 8.09 GiB
[taskcluster 2026-08-27T21:28:15.272Z] Peak System Memory Used: 9.30 GiB
[taskcluster 2026-08-27T21:28:15.272Z] Total System Memory: 16.00 GiB
[taskcluster 2026-08-27T21:28:15.272Z] Result: SUCCEEDED
[taskcluster 2026-08-27T21:28:15.273Z] === Task Finished ===
[taskcluster 2026-08-27T21:28:15.273Z] Task Duration: 9m0.926261s
[taskcluster 2026-08-27T21:28:15.485Z] Uploading artifact public/test_info/report.html from file /opt/worker/tasks/cltbld/build/blobber_upload_dir/report.html with content encoding "gzip", mime type "text/html; charset=utf-8" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.485Z] Uploading artifact public/test_info/marionette_errorsummary.log from file /opt/worker/tasks/cltbld/build/blobber_upload_dir/marionette_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.486Z] Uploading artifact public/build/perfherder-data-mozharness-actions.json from file /opt/worker/tasks/cltbld/public/build/perfherder-data-mozharness-actions.json with content encoding "gzip", mime type "application/json" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.486Z] Uploading artifact public/test_info/profile_resource-usage.json from file /opt/worker/tasks/cltbld/build/blobber_upload_dir/profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.488Z] Uploading artifact public/logs/localconfig.json from file /opt/worker/tasks/cltbld/logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.507Z] Uploading artifact public/fetch/perfherder-data-fetch-content.json from file /opt/worker/tasks/cltbld/perf/perfherder-data-fetch-content.json with content encoding "gzip", mime type "application/json" and expiry 2026-09-24T20:38:48.083Z
[taskcluster 2026-08-27T21:28:15.773Z] [mounts] Preserving cache: Moving "/opt/worker/tasks/cltbld/.task-cache/pip" to "/opt/worker/cache/X2xdqXOgRhCePqQVgXx1dA"
[taskcluster 2026-08-27T21:28:15.774Z] [mounts] Preserving cache: Moving "/opt/worker/tasks/cltbld/.task-cache/uv" to "/opt/worker/cache/T4GIBPGNR4WAtCWG1B3j0g"
[taskcluster 2026-08-27T21:28:15.852Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2026-09-24T20:38:48.083Z
Loading