1810157 - Intermittent toolkit/xre/test/marionette/test_fission_autostart.py TestFissionAutostart.test_fission_precedence | OSError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Timed out waiting for

Status: RESOLVED INCOMPLETE

(Toolkit :: Startup and Profile System, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-01-13T14:20:23.380Z] 14:20:23     INFO -  TEST-START | toolkit/xre/test/marionette/test_fission_autostart.py TestFissionAutostart.test_fission_precedence
[task 2023-01-13T14:20:23.381Z] 14:20:23     INFO -  1673619623381	Marionette	DEBUG	Accepted connection 3 from 127.0.0.1:52424
[task 2023-01-13T14:20:23.382Z] 14:20:23     INFO -  1673619623382	Marionette	DEBUG	3 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-01-13T14:20:23.383Z] 14:20:23     INFO -  1673619623383	Marionette	DEBUG	Waiting for initial application window
[task 2023-01-13T14:20:23.384Z] 14:20:23     INFO -  1673619623383	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=false
[task 2023-01-13T14:20:23.384Z] 14:20:23     INFO -  1673619623384	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (200ms)
[task 2023-01-13T14:20:23.384Z] 14:20:23     INFO -  1673619623384	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2023-01-13T14:20:23.384Z] 14:20:23     INFO -  1673619623384	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2023-01-13T14:20:23.387Z] 14:20:23     INFO -  1673619623386	Marionette	DEBUG	3 <- [1,1,null,{"sessionId":"e86deba8-c082-4419-88ab-c1e3f9b6b6e2","capabilities":{"browserName":"firefox","browserVersion":"110.0a1","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230113132657","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":7460,"moz:profile":"C:\\Users\\task_167361339990713\\AppData\\Local\\Temp\\tmpmpaowhi8.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-01-13T14:20:23.387Z] 14:20:23     INFO -  1673619623387	Marionette	DEBUG	3 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-01-13T14:20:23.387Z] 14:20:23     INFO -  1673619623387	Marionette	DEBUG	3 <- [1,2,null,{"value":null}]
[task 2023-01-13T14:20:23.388Z] 14:20:23     INFO -  1673619623388	Marionette	DEBUG	3 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-01-13T14:20:23.388Z] 14:20:23     INFO -  1673619623388	Marionette	DEBUG	3 <- [1,3,null,{"value":null}]
[task 2023-01-13T14:20:23.388Z] 14:20:23     INFO -  1673619623388	Marionette	DEBUG	3 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-01-13T14:20:23.388Z] 14:20:23     INFO -  1673619623389	Marionette	DEBUG	3 <- [1,4,null,{"value":null}]
[task 2023-01-13T14:20:23.390Z] 14:20:23     INFO -  1673619623389	Marionette	DEBUG	3 -> [0,5,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:23.390Z] 14:20:23     INFO -  1673619623390	Marionette	DEBUG	3 <- [1,5,null,{"value":"content"}]
[task 2023-01-13T14:20:23.390Z] 14:20:23     INFO -  1673619623390	Marionette	DEBUG	3 -> [0,6,"WebDriver:DeleteSession",{}]
[task 2023-01-13T14:20:23.392Z] 14:20:23     INFO -  1673619623392	Marionette	DEBUG	3 <- [1,6,null,{"value":null}]
[task 2023-01-13T14:20:23.393Z] 14:20:23     INFO -  1673619623392	Marionette	DEBUG	Closed connection 3
[task 2023-01-13T14:20:23.467Z] 14:20:23     INFO -  Application command: Z:\task_167361339990713\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_167361339990713\AppData\Local\Temp\tmpmhpxaesd.mozrunner
[task 2023-01-13T14:20:23.648Z] 14:20:23     INFO -  DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2023-01-13T14:20:23.665Z] 14:20:23     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase profile-before-change
[task 2023-01-13T14:20:23.672Z] 14:20:23     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase profile-before-change-telemetry
[task 2023-01-13T14:20:23.672Z] 14:20:23     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-01-13T14:20:23.672Z] 14:20:23     INFO -  DEBUG: Adding blocker IOUtils Blocker (xpcom-will-shutdown) for phase xpcom-will-shutdown
[task 2023-01-13T14:20:23.673Z] 14:20:23     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase IOUtils: waiting for xpcomWillShutdown IO to complete
[task 2023-01-13T14:20:23.700Z] 14:20:23     INFO -  DEBUG: Adding blocker Flush WebExtension StartupCache for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:23.804Z] 14:20:23     INFO -  DEBUG: Adding blocker JSON store: writing data for 'addonStartup' for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:23.810Z] 14:20:23     INFO -  DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2023-01-13T14:20:23.814Z] 14:20:23     INFO -  DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2023-01-13T14:20:23.815Z] 14:20:23     INFO -  DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:23.816Z] 14:20:23     INFO -  DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2023-01-13T14:20:23.817Z] 14:20:23     INFO -  DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change and awaiting all checkpoints written for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:23.829Z] 14:20:23     INFO -  DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2023-01-13T14:20:23.862Z] 14:20:23     INFO -  DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2023-01-13T14:20:23.876Z] 14:20:23     INFO -  DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2023-01-13T14:20:23.879Z] 14:20:23     INFO -  DEBUG: Adding blocker TerminatoryTelemetry: Waiting to submit telemetry for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-01-13T14:20:23.881Z] 14:20:23     INFO -  1673619623881	Marionette	INFO	Marionette enabled
[task 2023-01-13T14:20:23.883Z] 14:20:23     INFO -  1673619623883	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-01-13T14:20:23.885Z] 14:20:23     INFO -  1673619623885	Marionette	INFO	Listening on port 2828
[task 2023-01-13T14:20:23.885Z] 14:20:23     INFO -  1673619623885	Marionette	DEBUG	Marionette is listening
[task 2023-01-13T14:20:23.943Z] 14:20:23     INFO -  DEBUG: Adding blocker PermissionManager: Flushing data for phase xpcom-will-shutdown
[task 2023-01-13T14:20:24.009Z] 14:20:24     INFO -  DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2023-01-13T14:20:24.014Z] 14:20:24     INFO -  DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2023-01-13T14:20:24.151Z] 14:20:24     INFO -  DEBUG: Adding blocker MediaShutdownManager: shutdown for phase profile-before-change
[task 2023-01-13T14:20:24.186Z] 14:20:24     INFO -  1673619624190	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:52428
[task 2023-01-13T14:20:24.202Z] 14:20:24     INFO -  1673619624215	Marionette	DEBUG	Closed connection 0
[task 2023-01-13T14:20:24.215Z] 14:20:24     INFO -  1673619624215	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:52429
[task 2023-01-13T14:20:24.242Z] 14:20:24     INFO -  1673619624242	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-01-13T14:20:24.244Z] 14:20:24     INFO -  1673619624245	Marionette	DEBUG	Waiting for initial application window
[task 2023-01-13T14:20:24.251Z] 14:20:24     INFO -  DEBUG: Adding blocker ServiceWorkerShutdownBlocker: shutting down Service Workers for phase profile-change-teardown
[task 2023-01-13T14:20:24.254Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db59919400 for phase xpcom-will-shutdown
[task 2023-01-13T14:20:24.254Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db59919400 for phase profile-before-change
[task 2023-01-13T14:20:24.255Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db59919400 for phase quit-application-granted
[task 2023-01-13T14:20:24.260Z] 14:20:24     INFO -  DEBUG: Adding blocker SitePermsAddonProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:24.261Z] 14:20:24     INFO -  DEBUG: Adding blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:24.272Z] 14:20:24     INFO -  DEBUG: Adding blocker JSON store: writing data for 'handlers' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:24.351Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db5b1f2100 for phase xpcom-will-shutdown
[task 2023-01-13T14:20:24.354Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db5b1f2100 for phase profile-before-change
[task 2023-01-13T14:20:24.354Z] 14:20:24     INFO -  DEBUG: Adding blocker ContentParent: id=1db5b1f2100 for phase quit-application-granted
[task 2023-01-13T14:20:24.479Z] 14:20:24     INFO -  DEBUG: Adding blocker JSON store: writing data for 'shieldpreferenceexperiments' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:24.500Z] 14:20:24     INFO -  DEBUG: Adding blocker Remote Settings profile-before-change for phase profile-before-change
[task 2023-01-13T14:20:24.525Z] 14:20:24     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T14:20:24.556Z] 14:20:24     INFO -  DEBUG: Adding blocker CookieBannerDomainPrefService: write content pref before profile-before-change. for phase profile-before-change
[task 2023-01-13T14:20:24.569Z] 14:20:24     INFO -  DEBUG: Adding blocker Sqlite.sys.mjs shutdown blocker for phase profile-before-change
[task 2023-01-13T14:20:24.569Z] 14:20:24     INFO -  DEBUG: Adding blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-01-13T14:20:24.570Z] 14:20:24     INFO -  DEBUG: Adding blocker Closing ContentPrefService2 connection. for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-01-13T14:20:24.571Z] 14:20:24     INFO -  DEBUG: Adding blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:24.601Z] 14:20:24     INFO -  DEBUG: Completed blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:24.604Z] 14:20:24     INFO -  DEBUG: Adding blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:24.604Z] 14:20:24     INFO -  DEBUG: Adding blocker Transaction (2) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:24.604Z] 14:20:24     INFO -  DEBUG: Completed blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:24.608Z] 14:20:24     INFO -  DEBUG: Completed blocker Transaction (2) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.249Z] 14:20:25     INFO -  DEBUG: Adding blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2023-01-13T14:20:25.262Z] 14:20:25     INFO -  DEBUG: Adding blocker Places Clients shutdown for phase profile-change-teardown
[task 2023-01-13T14:20:25.262Z] 14:20:25     INFO -  DEBUG: Adding blocker Places Connection shutdown for phase profile-before-change
[task 2023-01-13T14:20:25.274Z] 14:20:25     INFO -  DEBUG: Adding blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2023-01-13T14:20:25.294Z] 14:20:25     INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167361339990713\\AppData\\Local\\Temp\\tmpmhpxaesd.mozrunner\\search.json.mozlz4", (void 0)))
[task 2023-01-13T14:20:25.309Z] 14:20:25     INFO -  DEBUG: Adding blocker Transaction (3) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.329Z] 14:20:25     INFO -  DEBUG: Completed blocker Transaction (3) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.418Z] 14:20:25     INFO -  DEBUG: Adding blocker ContextualIdentityService: writing data for phase profile-before-change
[task 2023-01-13T14:20:25.428Z] 14:20:25     INFO -  DEBUG: Adding blocker JSON store: writing data for 'logins' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:25.481Z] 14:20:25     INFO -  DEBUG: Adding blocker JSON store: writing data for 'ExperimentStoreData' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:25.904Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-01-13T14:20:25.906Z] 14:20:25     INFO -  DEBUG: Adding blocker PlacesUtils wrapped connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2023-01-13T14:20:25.906Z] 14:20:25     INFO -  DEBUG: Adding blocker PlacesUtils wrapped connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-01-13T14:20:25.911Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: PlacesUIUtils: maybeAddImportButton (0) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.915Z] 14:20:25     INFO -  DEBUG: Adding blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2023-01-13T14:20:25.916Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: PlacesExpiration.jsm: setup (1) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.917Z] 14:20:25     INFO -  DEBUG: Completed blocker places.sqlite#0: PlacesUIUtils: maybeAddImportButton (0) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.922Z] 14:20:25     INFO -  DEBUG: Completed blocker places.sqlite#0: PlacesExpiration.jsm: setup (1) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.945Z] 14:20:25     INFO -  DEBUG: Adding blocker Transaction (2) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.946Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: eraseEverything (3) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.977Z] 14:20:25     INFO -  DEBUG: Completed blocker Transaction (2) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.983Z] 14:20:25     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: eraseEverything (3) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.983Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: fetchBookmark (4) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.984Z] 14:20:25     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: fetchBookmark (4) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.984Z] 14:20:25     INFO -  DEBUG: Adding blocker Transaction (5) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.985Z] 14:20:25     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: insertBookmarkTree (6) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:25.997Z] 14:20:25     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T14:20:26.012Z] 14:20:26     INFO -  DEBUG: Completed blocker Transaction (5) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.012Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: insertBookmarkTree (6) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.012Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: GuidHelper.getItemId (7) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.019Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: GuidHelper.getItemId (7) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.020Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: PlacesUtils.keywords.insert (8) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.020Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: PlacesUtils: promiseKeywordsCache (9) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.022Z] 14:20:26     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T14:20:26.023Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: PlacesUtils: promiseKeywordsCache (9) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.023Z] 14:20:26     INFO -  DEBUG: Adding blocker Transaction (10) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.038Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: fetchBookmarksByURL (11) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.046Z] 14:20:26     INFO -  DEBUG: Completed blocker Transaction (10) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.047Z] 14:20:26     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T14:20:26.049Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#1: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-01-13T14:20:26.049Z] 14:20:26     INFO -  DEBUG: Adding blocker PlacesUtils read-only connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2023-01-13T14:20:26.049Z] 14:20:26     INFO -  DEBUG: Adding blocker PlacesUtils read-only connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-01-13T14:20:26.058Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: fetchBookmarksByURL (11) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.059Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: PlacesUtils.keywords.insert (8) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.059Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: PlacesUtils.keywords.insert (12) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.060Z] 14:20:26     INFO -  DEBUG: Adding blocker Transaction (13) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.063Z] 14:20:26     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T14:20:26.076Z] 14:20:26     INFO -  DEBUG: Adding blocker Search service: shutting down for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:26.085Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: fetchBookmarksByURL (14) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.085Z] 14:20:26     INFO -  DEBUG: Completed blocker Transaction (13) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.088Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: fetchBookmarksByURL (14) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.088Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: PlacesUtils.keywords.insert (12) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.090Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: fetchBookmark (15) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.117Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5872f100 for phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.123Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5872f100 for phase profile-before-change
[task 2023-01-13T14:20:26.123Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5872f100 for phase quit-application-granted
[task 2023-01-13T14:20:26.125Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced8d00 for phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.126Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced8d00 for phase profile-before-change
[task 2023-01-13T14:20:26.127Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced8d00 for phase quit-application-granted
[task 2023-01-13T14:20:26.138Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced9700 for phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.141Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced9700 for phase profile-before-change
[task 2023-01-13T14:20:26.142Z] 14:20:26     INFO -  DEBUG: Adding blocker ContentParent: id=1db5ced9700 for phase quit-application-granted
[task 2023-01-13T14:20:26.149Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: fetchBookmark (15) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.150Z] 14:20:26     INFO -  DEBUG: Adding blocker Transaction (16) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.150Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: Bookmarks.jsm: insertBookmarkTree (17) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.151Z] 14:20:26     INFO -  DEBUG: Adding blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2023-01-13T14:20:26.176Z] 14:20:26     INFO -  1673619626177	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2023-01-13T14:20:26.178Z] 14:20:26     INFO -  DEBUG: Adding blocker ScriptPreloader: Saving bytecode cache for phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.179Z] 14:20:26     INFO -  1673619626183	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=false
[task 2023-01-13T14:20:26.184Z] 14:20:26     INFO -  1673619626183	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (200ms)
[task 2023-01-13T14:20:26.185Z] 14:20:26     INFO -  1673619626184	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2023-01-13T14:20:26.185Z] 14:20:26     INFO -  1673619626184	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2023-01-13T14:20:26.196Z] 14:20:26     INFO -  1673619626196	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"8ae07f43-a0a8-44e4-9866-47baef264c38","capabilities":{"browserName":"firefox","browserVersion":"110.0a1","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230113132657","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":8416,"moz:profile":"C:\\Users\\task_167361339990713\\AppData\\Local\\Temp\\tmpmhpxaesd.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-01-13T14:20:26.200Z] 14:20:26     INFO -  DEBUG: Completed blocker Transaction (16) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.201Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: Bookmarks.jsm: insertBookmarkTree (17) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.201Z] 14:20:26     INFO -  DEBUG: Adding blocker places.sqlite#0: GuidHelper.getItemId (18) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.206Z] 14:20:26     INFO -  1673619626206	Marionette	DEBUG	1 -> [0,2,"Marionette:SetContext",{"value":"content"}]
[task 2023-01-13T14:20:26.207Z] 14:20:26     INFO -  1673619626206	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2023-01-13T14:20:26.208Z] 14:20:26     INFO -  1673619626207	Marionette	DEBUG	1 -> [0,3,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.208Z] 14:20:26     INFO -  1673619626207	Marionette	DEBUG	1 <- [1,3,null,{"value":null}]
[task 2023-01-13T14:20:26.213Z] 14:20:26     INFO -  DEBUG: Completed blocker places.sqlite#0: GuidHelper.getItemId (18) for phase places.sqlite#0: waiting for clients
[task 2023-01-13T14:20:26.224Z] 14:20:26     INFO -  1673619626235	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:26.235Z] 14:20:26     INFO -  1673619626235	Marionette	DEBUG	1 <- [1,4,null,{"value":"chrome"}]
[task 2023-01-13T14:20:26.236Z] 14:20:26     INFO -  1673619626236	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.236Z] 14:20:26     INFO -  1673619626236	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2023-01-13T14:20:26.239Z] 14:20:26     INFO -  1673619626238	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"// We're running in a function, in a sandbox, that inherits from an\n          // X-ray wrapped window. Anything we want to be globally available\n          // needs to be defined on that window.\n          window.env = Services.env;","args":[],"newSandbox":false,"sandbox":"fission-autostart","line":44,"filename":"Z:\\task_167361339990713\\build\\tests\\marionette\\tests\\toolkit\\xre\\test\\marionette\\test_fission_autostart.py"}]
[task 2023-01-13T14:20:26.241Z] 14:20:26     INFO -  1673619626241	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 8416
[task 2023-01-13T14:20:26.242Z] 14:20:26     INFO -  1673619626242	Marionette	TRACE	[1] MarionetteCommands actor created for window id 2
[task 2023-01-13T14:20:26.244Z] 14:20:26     INFO -  1673619626244	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2023-01-13T14:20:26.244Z] 14:20:26     INFO -  1673619626244	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.244Z] 14:20:26     INFO -  1673619626244	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2023-01-13T14:20:26.245Z] 14:20:26     INFO -  1673619626245	Marionette	DEBUG	1 -> [0,8,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:26.245Z] 14:20:26     INFO -  1673619626245	Marionette	DEBUG	1 <- [1,8,null,{"value":"chrome"}]
[task 2023-01-13T14:20:26.246Z] 14:20:26     INFO -  1673619626246	Marionette	DEBUG	1 -> [0,9,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.246Z] 14:20:26     INFO -  1673619626246	Marionette	DEBUG	1 <- [1,9,null,{"value":null}]
[task 2023-01-13T14:20:26.248Z] 14:20:26     INFO -  1673619626247	Marionette	DEBUG	1 -> [0,10,"WebDriver:ExecuteScript",{"script":"let win = Services.wm.getMostRecentWindow(\"navigator:browser\");\n          return {\n            fissionAutostart: Services.app ... ssion.autostart.session\"),\n            dynamicFissionAutostart: Services.prefs.getBoolPref(\"fission.autostart\"),\n          };","args":[],"newSandbox":false,"sandbox":"fission-autostart","line":44,"filename":"Z:\\task_167361339990713\\build\\tests\\marionette\\tests\\toolkit\\xre\\test\\marionette\\test_fission_autostart.py"}]
[task 2023-01-13T14:20:26.249Z] 14:20:26     INFO -  1673619626248	Marionette	DEBUG	1 <- [1,10,null,{"value":{"fissionAutostart":true,"fissionExperimentStatus":0,"decisionStatus":7,"decisionStatusString":"enabledByDefault","useRemoteSubframes":true,"fissionAutostartSession":true,"dynamicFissionAutostart":true}}]
[task 2023-01-13T14:20:26.249Z] 14:20:26     INFO -  1673619626249	Marionette	DEBUG	1 -> [0,11,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.249Z] 14:20:26     INFO -  1673619626250	Marionette	DEBUG	1 <- [1,11,null,{"value":null}]
[task 2023-01-13T14:20:26.250Z] 14:20:26     INFO -  1673619626250	Marionette	DEBUG	1 -> [0,12,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:26.250Z] 14:20:26     INFO -  1673619626250	Marionette	DEBUG	1 <- [1,12,null,{"value":"chrome"}]
[task 2023-01-13T14:20:26.251Z] 14:20:26     INFO -  1673619626251	Marionette	DEBUG	1 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.251Z] 14:20:26     INFO -  1673619626251	Marionette	DEBUG	1 <- [1,13,null,{"value":null}]
[task 2023-01-13T14:20:26.253Z] 14:20:26     INFO -  1673619626252	Marionette	DEBUG	1 -> [0,14,"WebDriver:ExecuteScript",{"script":"let win = Services.wm.getMostRecentWindow(\"navigator:browser\");\n          return {\n            fissionAutostart: Services.app ... ssion.autostart.session\"),\n            dynamicFissionAutostart: Services.prefs.getBoolPref(\"fission.autostart\"),\n          };","args":[],"newSandbox":false,"sandbox":"fission-autostart","line":44,"filename":"Z:\\task_167361339990713\\build\\tests\\marionette\\tests\\toolkit\\xre\\test\\marionette\\test_fission_autostart.py"}]
[task 2023-01-13T14:20:26.254Z] 14:20:26     INFO -  1673619626253	Marionette	DEBUG	1 <- [1,14,null,{"value":{"fissionAutostart":true,"fissionExperimentStatus":0,"decisionStatus":7,"decisionStatusString":"enabledByDefault","useRemoteSubframes":true,"fissionAutostartSession":true,"dynamicFissionAutostart":true}}]
[task 2023-01-13T14:20:26.254Z] 14:20:26     INFO -  1673619626254	Marionette	DEBUG	1 -> [0,15,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.254Z] 14:20:26     INFO -  1673619626254	Marionette	DEBUG	1 <- [1,15,null,{"value":null}]
[task 2023-01-13T14:20:26.254Z] 14:20:26     INFO -  1673619626254	Marionette	DEBUG	1 -> [0,16,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:26.255Z] 14:20:26     INFO -  1673619626254	Marionette	DEBUG	1 <- [1,16,null,{"value":"chrome"}]
[task 2023-01-13T14:20:26.255Z] 14:20:26     INFO -  1673619626255	Marionette	DEBUG	1 -> [0,17,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.255Z] 14:20:26     INFO -  1673619626255	Marionette	DEBUG	1 <- [1,17,null,{"value":null}]
[task 2023-01-13T14:20:26.257Z] 14:20:26     INFO -  1673619626256	Marionette	DEBUG	1 -> [0,18,"WebDriver:ExecuteScript",{"script":"const { Preferences } = ChromeUtils.importESModule(\n                  \"resource://gre/modules/Preferences.sys.mjs\"\n           ... guments[2];\n\n                prefs = new Preferences({defaultBranch: defaultBranch});\n                prefs.set(pref, value);","args":["fission.autostart",false,false],"newSandbox":true,"sandbox":"default","line":831,"filename":"Z:\\task_167361339990713\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py"}]
[task 2023-01-13T14:20:26.258Z] 14:20:26     INFO -  1673619626258	Marionette	DEBUG	1 <- [1,18,null,{"value":null}]
[task 2023-01-13T14:20:26.259Z] 14:20:26     INFO -  1673619626259	Marionette	DEBUG	1 -> [0,19,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-01-13T14:20:26.259Z] 14:20:26     INFO -  1673619626259	Marionette	DEBUG	1 <- [1,19,null,{"value":null}]
[task 2023-01-13T14:20:26.259Z] 14:20:26     INFO -  1673619626259	Marionette	DEBUG	1 -> [0,20,"Marionette:GetContext",{}]
[task 2023-01-13T14:20:26.260Z] 14:20:26     INFO -  1673619626259	Marionette	DEBUG	1 <- [1,20,null,{"value":"chrome"}]
[task 2023-01-13T14:20:26.260Z] 14:20:26     INFO -  1673619626260	Marionette	DEBUG	1 -> [0,21,"Marionette:SetContext",{"value":"chrome"}]
<...>
[task 2023-01-13T14:20:26.525Z] 14:20:26     INFO -  observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T14:20:26.525Z] 14:20:26     INFO -  WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.525Z] 14:20:26     INFO -  WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-13T14:20:26.525Z] 14:20:26     INFO -  addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-13T14:20:26.526Z] 14:20:26     INFO -  addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-13T14:20:26.526Z] 14:20:26     INFO -  setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-13T14:20:26.526Z] 14:20:26     INFO -  @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-13T14:20:26.526Z] 14:20:26     INFO -  @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-13T14:20:26.526Z] 14:20:26     INFO -  @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-13T14:20:26.527Z] 14:20:26     INFO -  _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-13T14:20:26.527Z] 14:20:26     INFO -  setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-13T14:20:26.527Z] 14:20:26     INFO -  setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-13T14:20:26.527Z] 14:20:26     INFO -  setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-13T14:20:26.527Z] 14:20:26     INFO -  observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T14:20:26.528Z] 14:20:26     INFO -  DEBUG: Completed blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2023-01-13T14:20:26.528Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.529Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.529Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.529Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.530Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.531Z] 14:20:26     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-13T14:20:26.890Z] 14:20:26     INFO -  DEBUG: Completed blocker TerminatoryTelemetry: Waiting to submit telemetry for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-01-13T14:20:26.890Z] 14:20:26     INFO -  DEBUG: Finished phase profile-before-change-telemetry
[task 2023-01-13T14:20:26.892Z] 14:20:26     INFO -  DEBUG: Starting phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.892Z] 14:20:26     INFO -  DEBUG: Spinning the event loop
[task 2023-01-13T14:20:26.892Z] 14:20:26     INFO -  DEBUG: Completed blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.920Z] 14:20:26     INFO -  DEBUG: Finished phase xpcom-will-shutdown
[task 2023-01-13T14:20:26.921Z] 14:20:26     INFO -  DEBUG: Starting phase web-workers-shutdown
[task 2023-01-13T14:20:26.921Z] 14:20:26     INFO -  DEBUG: Spinning the event loop
[task 2023-01-13T14:20:26.921Z] 14:20:26     INFO -  DEBUG: Finished phase web-workers-shutdown
[task 2023-01-13T14:20:51.414Z] 14:20:51     INFO -  Application command: Z:\task_167361339990713\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_167361339990713\AppData\Local\Temp\tmplizt62my.mozrunner
[task 2023-01-13T14:20:51.592Z] 14:20:51     INFO -  DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2023-01-13T14:20:51.621Z] 14:20:51     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase profile-before-change
[task 2023-01-13T14:20:51.621Z] 14:20:51     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase profile-before-change-telemetry
[task 2023-01-13T14:20:51.622Z] 14:20:51     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-01-13T14:20:51.622Z] 14:20:51     INFO -  DEBUG: Adding blocker IOUtils Blocker (xpcom-will-shutdown) for phase xpcom-will-shutdown
[task 2023-01-13T14:20:51.622Z] 14:20:51     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change-telemetry) for phase IOUtils: waiting for xpcomWillShutdown IO to complete
[task 2023-01-13T14:20:51.649Z] 14:20:51     INFO -  DEBUG: Adding blocker Flush WebExtension StartupCache for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:51.745Z] 14:20:51     INFO -  DEBUG: Adding blocker JSON store: writing data for 'addonStartup' for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:51.749Z] 14:20:51     INFO -  DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2023-01-13T14:20:51.753Z] 14:20:51     INFO -  DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2023-01-13T14:20:51.754Z] 14:20:51     INFO -  DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-01-13T14:20:51.754Z] 14:20:51     INFO -  DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2023-01-13T14:20:51.756Z] 14:20:51     INFO -  DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change and awaiting all checkpoints written for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-01-13T14:20:51.767Z] 14:20:51     INFO -  DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2023-01-13T14:20:51.800Z] 14:20:51     INFO -  DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2023-01-13T14:20:51.813Z] 14:20:51     INFO -  DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2023-01-13T14:20:51.815Z] 14:20:51     INFO -  DEBUG: Adding blocker TerminatoryTelemetry: Waiting to submit telemetry for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-01-13T14:20:51.817Z] 14:20:51     INFO -  1673619651817	Marionette	INFO	Marionette enabled
[task 2023-01-13T14:20:51.819Z] 14:20:51     INFO -  1673619651819	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-01-13T14:20:51.821Z] 14:20:51     INFO -  1673619651820	Marionette	INFO	Listening on port 2828
[task 2023-01-13T14:20:51.821Z] 14:20:51     INFO -  1673619651821	Marionette	DEBUG	Marionette is listening
[task 2023-01-13T14:24:03.654Z] 14:24:03    ERROR -  TEST-UNEXPECTED-ERROR | toolkit/xre/test/marionette/test_fission_autostart.py TestFissionAutostart.test_fission_precedence | OSError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Timed out waiting for connection on 127.0.0.1:2828!)
[task 2023-01-13T14:24:03.667Z] 14:24:03     INFO -  Traceback (most recent call last):
[task 2023-01-13T14:24:03.667Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 231, in run
[task 2023-01-13T14:24:03.667Z] 14:24:03     INFO -      self.tearDown()
[task 2023-01-13T14:24:03.668Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\tests\marionette\tests\toolkit\xre\test\marionette\test_fission_autostart.py", line 178, in tearDown
[task 2023-01-13T14:24:03.668Z] 14:24:03     INFO -      self.marionette.restart(in_app=False, clean=True)
[task 2023-01-13T14:24:03.668Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_driver\decorators.py", line 34, in _
[task 2023-01-13T14:24:03.668Z] 14:24:03     INFO -      m._handle_socket_failure()
[task 2023-01-13T14:24:03.669Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_driver\marionette.py", line 740, in _handle_socket_failure
[task 2023-01-13T14:24:03.669Z] 14:24:03     INFO -      reraise(
[task 2023-01-13T14:24:03.669Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2023-01-13T14:24:03.669Z] 14:24:03     INFO -      raise value.with_traceback(tb)
[task 2023-01-13T14:24:03.669Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_driver\decorators.py", line 24, in _
[task 2023-01-13T14:24:03.670Z] 14:24:03     INFO -      return func(*args, **kwargs)
[task 2023-01-13T14:24:03.670Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1189, in restart
[task 2023-01-13T14:24:03.670Z] 14:24:03     INFO -      self.raise_for_port(timeout=self.DEFAULT_STARTUP_TIMEOUT)
[task 2023-01-13T14:24:03.670Z] 14:24:03     INFO -    File "Z:\task_167361339990713\build\venv\lib\site-packages\marionette_driver\marionette.py", line 631, in raise_for_port
[task 2023-01-13T14:24:03.671Z] 14:24:03     INFO -      raise socket.timeout(
[task 2023-01-13T14:24:03.671Z] 14:24:03     INFO -  TEST-INFO took 220258ms
[task 2023-01-13T14:24:03.671Z] 14:24:03     INFO -  TEST-START | toolkit/xre/test/marionette/test_fission_autostart.py TestFissionAutostart.test_fission_startup

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • opt: 1

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

Comment 4

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

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