Open Bug 2020146 Opened 5 months ago Updated 4 days ago

Perma mochitest plain [taskcluster:error] Aborting task... | single tracking bug

Categories

(Testing :: Mochitest, defect, P5)

defect

Tracking

(Not tracked)

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

Details

(Keywords: intermittent-failure)

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


[task 2026-02-28T13:43:40.196+00:00] 13:43:40     INFO - runtests.py | Running http tests: end. status: 0
[task 2026-02-28T13:43:40.196+00:00] 13:43:40     INFO - Stopping web server
[task 2026-02-28T13:43:40.207+00:00] 13:43:40     INFO - Server shut down.
[task 2026-02-28T13:43:40.207+00:00] 13:43:40     INFO - Web server killed.
[task 2026-02-28T13:43:40.207+00:00] 13:43:40     INFO - Stopping web socket server
[task 2026-02-28T13:43:40.207+00:00] 13:43:40     INFO - Stopping ssltunnel
[task 2026-02-28T13:43:40.208+00:00] 13:43:40     INFO - Stopping gst for v4l2loopback
[task 2026-02-28T13:43:40.209+00:00] 13:43:40  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2026-02-28T13:43:40.272+00:00] 13:43:40     INFO - Buffered messages finished
[task 2026-02-28T13:43:40.272+00:00] 13:43:40     INFO - Running manifest: dom/filesystem/compat/tests/mochitest.toml
[task 2026-02-28T13:43:40.329+00:00] 13:43:40     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:43:40.341+00:00] 13:43:40     INFO -  Setting pipeline to PAUSED ...
[task 2026-02-28T13:43:40.341+00:00] 13:43:40     INFO -  Pipeline is PREROLLING ...
[task 2026-02-28T13:43:40.343+00:00] 13:43:40     INFO -  Pipeline is PREROLLED ...
[task 2026-02-28T13:43:40.343+00:00] 13:43:40     INFO -  Setting pipeline to PLAYING ...
[task 2026-02-28T13:43:40.343+00:00] 13:43:40     INFO -  Redistribute latency...
[task 2026-02-28T13:43:40.343+00:00] 13:43:40     INFO -  New clock: GstSystemClock
[task 2026-02-28T13:43:40.376+00:00] 13:43:40     INFO -  Got EOS from element "pipeline0".
[task 2026-02-28T13:43:40.376+00:00] 13:43:40     INFO -  Execution ended after 0:00:00.033490649
[task 2026-02-28T13:43:40.377+00:00] 13:43:40     INFO -  Setting pipeline to NULL ...
[task 2026-02-28T13:43:40.505+00:00] 13:43:40     INFO - PID 30919 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2026-02-28T13:43:40.505+00:00] 13:43:40     INFO - 
[task 2026-02-28T13:43:40.851+00:00] 13:43:40     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:43:40.852+00:00] 13:43:40     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:43:40.853+00:00] 13:43:40     INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-e', "const _PROFILE_PATH = '/tmp/tmpd85oltxw.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false; const _HTTPD_PATH = '/builds/worker/workspace/build/tests/bin/components';", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2026-02-28T13:43:40.853+00:00] 13:43:40     INFO - runtests.py | Server pid: 30933
[task 2026-02-28T13:43:40.853+00:00] 13:43:40     INFO - runtests.py | Websocket server pid: 30934
[task 2026-02-28T13:43:40.854+00:00] 13:43:40     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:43:40.854+00:00] 13:43:40     INFO - runtests.py | SSL tunnel pid: 30935
[task 2026-02-28T13:43:41.154+00:00] 13:43:41     INFO - use http3 server: 0
[task 2026-02-28T13:43:41.156+00:00] 13:43:41     INFO - runtests.py | Running with scheme: http
[task 2026-02-28T13:43:41.156+00:00] 13:43:41     INFO - runtests.py | Running with e10s: True
[task 2026-02-28T13:43:41.156+00:00] 13:43:41     INFO - runtests.py | Running with fission: True
[task 2026-02-28T13:43:41.157+00:00] 13:43:41     INFO - runtests.py | Running with cross-origin iframes: False
[task 2026-02-28T13:43:41.157+00:00] 13:43:41     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2026-02-28T13:43:41.157+00:00] 13:43:41     INFO - runtests.py | Running http tests: start.
[task 2026-02-28T13:43:41.157+00:00] 13:43:41     INFO - 
[task 2026-02-28T13:43:41.161+00:00] 13:43:41     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -remote-allow-system-access -foreground -profile /tmp/tmpd85oltxw.mozrunner
[task 2026-02-28T13:43:41.165+00:00] 13:43:41     INFO - runtests.py | Application pid: 30979
[task 2026-02-28T13:43:41.165+00:00] 13:43:41     INFO - TEST-INFO | started process GECKO(30979)
[task 2026-02-28T13:43:43.597+00:00] 13:43:43     INFO - GECKO(30979) | libEGL warning: DRI3: Screen seems not DRI3 capable
[task 2026-02-28T13:43:43.598+00:00] 13:43:43     INFO - GECKO(30979) | libEGL warning: DRI3: Screen seems not DRI3 capable
[task 2026-02-28T13:43:43.659+00:00] 13:43:43     INFO - GECKO(30979) | MESA: error: ZINK: failed to choose pdev
[task 2026-02-28T13:43:43.662+00:00] 13:43:43     INFO - GECKO(30979) | 1772286223661	Marionette	INFO	Marionette enabled
[task 2026-02-28T13:43:43.670+00:00] 13:43:43     INFO - GECKO(30979) | 1772286223669	Marionette	TRACE	Received observer notification final-ui-startup
[task 2026-02-28T13:43:43.670+00:00] 13:43:43     INFO - GECKO(30979) | libEGL warning: egl: failed to create dri2 screen
[task 2026-02-28T13:43:44.129+00:00] 13:43:44     INFO - GECKO(30979) | console.error: "Warning: unrecognized command line flag" "-foreground"
[task 2026-02-28T13:43:44.286+00:00] 13:43:44     INFO - GECKO(30979) | 1772286224285	Marionette	INFO	Listening on port 2828
[task 2026-02-28T13:43:44.297+00:00] 13:43:44     INFO - GECKO(30979) | 1772286224296	Marionette	DEBUG	Marionette is listening
[task 2026-02-28T13:43:44.388+00:00] 13:43:44     INFO - GECKO(30979) | 1772286224387	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:59540
[task 2026-02-28T13:43:44.461+00:00] 13:43:44     INFO - GECKO(30979) | 1772286224460	Marionette	DEBUG	Closed connection 0
[task 2026-02-28T13:43:44.925+00:00] 13:43:44     INFO - GECKO(30979) | 1772286224924	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:59542
[task 2026-02-28T13:43:45.054+00:00] 13:43:45     INFO - GECKO(30979) | 1772286225052	Marionette	DEBUG	Closed connection 1
[task 2026-02-28T13:43:45.055+00:00] 13:43:45     INFO - GECKO(30979) | 1772286225054	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:59552
[task 2026-02-28T13:43:45.582+00:00] 13:43:45     INFO - GECKO(30979) | 1772286225581	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2026-02-28T13:43:45.625+00:00] 13:43:45     INFO - GECKO(30979) | 1772286225624	Marionette	DEBUG	Waiting for initial application window
[task 2026-02-28T13:43:46.468+00:00] 13:43:46     INFO - GECKO(30979) | [Parent 30979: Main Thread]: I/SlowChromeEvent Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out! chrome://browser/content/tabbrowser/tabs.js:51:12
[task 2026-02-28T13:43:49.534+00:00] 13:43:49     INFO - GECKO(30979) | warning: address range table at offset 0x78970 has a premature terminator entry at offset 0x789c0
[task 2026-02-28T13:43:49.535+00:00] 13:43:49     INFO - GECKO(30979) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7cda0
[task 2026-02-28T13:43:49.535+00:00] 13:43:49     INFO - GECKO(30979) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7cde0
[task 2026-02-28T13:43:49.536+00:00] 13:43:49     INFO - GECKO(30979) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7ce90
[task 2026-02-28T13:43:51.862+00:00] 13:43:51     INFO - GECKO(30979) | /builds/worker/workspace/build/application/firefox/llvm-symbolizer: error: '[anon:js-executable-memory]': No such file or directory
[task 2026-02-28T13:43:52.760+00:00] 13:43:52     INFO - GECKO(30979) | console.error: services.settings:
[task 2026-02-28T13:43:52.761+00:00] 13:43:52     INFO - GECKO(30979) |   Message: EmptyDatabaseError: "main/nimbus-desktop-experiments" has not been synced yet
[task 2026-02-28T13:43:52.762+00:00] 13:43:52     INFO - GECKO(30979) |   Stack:
[task 2026-02-28T13:43:52.762+00:00] 13:43:52     INFO - GECKO(30979) |     EmptyDatabaseError@resource://services-settings/Database.sys.mjs:19:5
[task 2026-02-28T13:43:52.763+00:00] 13:43:52     INFO - GECKO(30979) | list@resource://services-settings/Database.sys.mjs:96:13
[task 2026-02-28T13:43:52.764+00:00] 13:43:52     INFO - GECKO(30979) | async*get@resource://services-settings/RemoteSettingsClient.sys.mjs:567:28
[task 2026-02-28T13:43:52.764+00:00] 13:43:52     INFO - GECKO(30979) | async*getRecipesFromCollection@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:635:30
[task 2026-02-28T13:43:52.765+00:00] 13:43:52     INFO - GECKO(30979) | getRecipesFromAllCollections@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:543:39
[task 2026-02-28T13:43:52.765+00:00] 13:43:52     INFO - GECKO(30979) | #updateImpl@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:439:33
[task 2026-02-28T13:43:52.766+00:00] 13:43:52     INFO - GECKO(30979) | async*updateRecipes/<@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:392:53
[task 2026-02-28T13:43:52.766+00:00] 13:43:52     INFO - GECKO(30979) | LockGrantedCallback*withUpdateLock@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:349:24
[task 2026-02-28T13:43:52.767+00:00] 13:43:52     INFO - GECKO(30979) | updateRecipes@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:392:16
[task 2026-02-28T13:43:52.768+00:00] 13:43:52     INFO - GECKO(30979) | enable@resource://nimbus/lib/RemoteSettingsExperimentLoader.sys.mjs:318:16
[task 2026-02-28T13:43:52.768+00:00] 13:43:52     INFO - GECKO(30979) | init@resource://nimbus/ExperimentAPI.sys.mjs:303:28
[task 2026-02-28T13:43:52.768+00:00] 13:43:52     INFO - GECKO(30979) | async*finishInit@resource://normandy/Normandy.sys.mjs:109:30
[task 2026-02-28T13:43:52.769+00:00] 13:43:52     INFO - GECKO(30979) | async*init@resource://normandy/Normandy.sys.mjs:80:16
[task 2026-02-28T13:43:52.769+00:00] 13:43:52     INFO - GECKO(30979) | async*fn@resource://gre/modules/BrowserUtils.sys.mjs:54:65
[task 2026-02-28T13:43:52.770+00:00] 13:43:52     INFO - GECKO(30979) | callSingleListener@resource://gre/modules/BrowserUtils.sys.mjs:591:15
[task 2026-02-28T13:43:52.771+00:00] 13:43:52     INFO - GECKO(30979) | callModulesFromCategory@resource://gre/modules/BrowserUtils.sys.mjs:632:23
[task 2026-02-28T13:43:52.771+00:00] 13:43:52     INFO - GECKO(30979) | BG__beforeUIStartup@resource:///modules/BrowserGlue.sys.mjs:413:23
[task 2026-02-28T13:43:52.771+00:00] 13:43:52     INFO - GECKO(30979) | BG_observe@resource:///modules/BrowserGlue.sys.mjs:193:14
[task 2026-02-28T13:43:55.309+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235307	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2026-02-28T13:43:55.330+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235329	RemoteAgent	TRACE	[10] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2026-02-28T13:43:55.331+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235330	RemoteAgent	TRACE	[10] ProgressListener Setting unload timer (40000ms)
[task 2026-02-28T13:43:55.334+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235333	RemoteAgent	TRACE	[10] Wait for initial navigation: isUncommittedInitial=false, isLoadingDocument=false
[task 2026-02-28T13:43:55.335+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235334	RemoteAgent	TRACE	[10] Document already finished loading: about:blank
[task 2026-02-28T13:43:55.335+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235334	RemoteAgent	TRACE	[10] ProgressListener Stop: has error=false url=about:blank
[task 2026-02-28T13:43:55.412+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235409	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"4c771a0a-91c2-4254-b3ce-5a7e0879117d","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"150.0a1","platformName":"linux","setWindowRect":true,"unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:150.0) Gecko/20100101 Firefox/150.0","moz:buildID":"20260228093326","moz:headless":false,"moz:platformVersion":"6.14.0-1021-gcp","moz:processID":30979,"moz:profile":"/tmp/tmpd85oltxw.mozrunner","moz:shutdownTimeout":360000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2026-02-28T13:43:55.441+00:00] 13:43:55     INFO - GECKO(30979) | 1772286235440	Marionette	DEBUG	2 -> [0,2,"Addon:Install",{"temporary":false,"path":"/tmp/tmp_rr7bq5x.zip"}]
[task 2026-02-28T13:43:56.083+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236081	Marionette	DEBUG	2 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2026-02-28T13:43:56.121+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236120	Marionette	DEBUG	2 -> [0,3,"Addon:Install",{"temporary":false,"path":"/tmp/tmp4x0rqf71.zip"}]
[task 2026-02-28T13:43:56.227+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236225	Marionette	DEBUG	2 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2026-02-28T13:43:56.236+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236235	Marionette	DEBUG	2 -> [0,4,"Marionette:GetContext",{}]
[task 2026-02-28T13:43:56.237+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236236	Marionette	DEBUG	2 <- [1,4,null,{"value":"content"}]
[task 2026-02-28T13:43:56.238+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236238	Marionette	DEBUG	2 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2026-02-28T13:43:56.240+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236239	Marionette	DEBUG	2 <- [1,5,null,{"value":null}]
[task 2026-02-28T13:43:56.245+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236243	Marionette	DEBUG	2 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, v. 2.0. If a copy of the MPL was not distr ... \n// the flavor and url to load.\nlet ev = new CustomEvent(\"mochitest-load\", { detail: [flavor, url] });\nwin.dispatchEvent(ev);","args":[{"flavor":"mochitest","testUrl":"http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true&ignorePrefsFile=ignorePrefs.json"}],"newSandbox":true,"sandbox":"default","line":2156,"filename":"tests/mochitest/runtests.py"}]
[task 2026-02-28T13:43:56.270+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236269	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 30979
[task 2026-02-28T13:43:56.274+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236273	Marionette	TRACE	[1] MarionetteCommands actor created for window id 2
[task 2026-02-28T13:43:56.344+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236344	Marionette	DEBUG	2 <- [1,6,null,{"value":null}]
[task 2026-02-28T13:43:56.418+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236417	Marionette	DEBUG	2 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2026-02-28T13:43:56.419+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236418	Marionette	DEBUG	2 <- [1,7,null,{"value":null}]
[task 2026-02-28T13:43:56.442+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236441	Marionette	DEBUG	2 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2026-02-28T13:43:56.444+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236443	Marionette	TRACE	[1] MarionetteCommands actor destroyed for window id 2
[task 2026-02-28T13:43:56.460+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236459	Marionette	DEBUG	2 <- [1,8,null,{"value":null}]
[task 2026-02-28T13:43:56.520+00:00] 13:43:56     INFO - runtests.py | Waiting for browser...
[task 2026-02-28T13:43:56.531+00:00] 13:43:56     INFO - GECKO(30979) | 1772286236528	Marionette	DEBUG	Closed connection 2
[task 2026-02-28T13:43:57.420+00:00] 13:43:57     INFO - SimpleTest START
[task 2026-02-28T13:43:57.423+00:00] 13:43:57     INFO - Dumping test context:
[task 2026-02-28T13:43:57.423+00:00] 13:43:57     INFO -   fission.autostart=true
[task 2026-02-28T13:43:57.440+00:00] 13:43:57     INFO - TEST-START | dom/filesystem/compat/tests/test_basic.html
[task 2026-02-28T13:43:58.323+00:00] 13:43:58     INFO - GECKO(30979) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2026-02-28T13:43:58.323+00:00] 13:43:58     INFO - GECKO(30979) | MEMORY STAT heapAllocated not supported in this build configuration.
[task 2026-02-28T13:43:58.324+00:00] 13:43:58     INFO - GECKO(30979) | MEMORY STAT | vsize 120588978MB | residentFast 269MB
[task 2026-02-28T13:43:58.561+00:00] 13:43:58     INFO - TEST-PASS | dom/filesystem/compat/tests/test_basic.html | took 1121ms
[task 2026-02-28T13:43:58.727+00:00] 13:43:58     INFO - TEST-START | dom/filesystem/compat/tests/test_formSubmission.html
[task 2026-02-28T13:43:59.691+00:00] 13:43:59     INFO - GECKO(30979) | MEMORY STAT | vsize 120588993MB | residentFast 294MB
[task 2026-02-28T13:43:59.779+00:00] 13:43:59     INFO - TEST-PASS | dom/filesystem/compat/tests/test_formSubmission.html | took 1052ms
[task 2026-02-28T13:43:59.980+00:00] 13:43:59     INFO - TEST-START | dom/filesystem/compat/tests/test_no_dnd.html
[task 2026-02-28T13:44:00.257+00:00] 13:44:00     INFO - GECKO(30979) | MEMORY STAT | vsize 120588994MB | residentFast 300MB
[task 2026-02-28T13:44:00.392+00:00] 13:44:00     INFO - TEST-PASS | dom/filesystem/compat/tests/test_no_dnd.html | took 412ms
[task 2026-02-28T13:44:00.546+00:00] 13:44:00     INFO - TEST-START | Shutdown
[task 2026-02-28T13:44:00.547+00:00] 13:44:00     INFO - Passed:  108
[task 2026-02-28T13:44:00.548+00:00] 13:44:00     INFO - Failed:  0
[task 2026-02-28T13:44:00.548+00:00] 13:44:00     INFO - Todo:    0
[task 2026-02-28T13:44:00.549+00:00] 13:44:00     INFO - Mode:    e10s
[task 2026-02-28T13:44:00.550+00:00] 13:44:00     INFO - Slowest: 1053ms - /tests/dom/filesystem/compat/tests/test_basic.html
[task 2026-02-28T13:44:00.552+00:00] 13:44:00     INFO - SimpleTest FINISHED
[task 2026-02-28T13:44:00.553+00:00] 13:44:00     INFO - TEST-INFO | Ran 1 Loops
[task 2026-02-28T13:44:00.553+00:00] 13:44:00     INFO - SimpleTest FINISHED
[task 2026-02-28T13:44:03.620+00:00] 13:44:03     INFO - GECKO(30979) | 1772286243619	Marionette	TRACE	Received observer notification quit-application
[task 2026-02-28T13:44:03.621+00:00] 13:44:03     INFO - GECKO(30979) | 1772286243619	Marionette	TRACE	Application is shutting down with reason: "shutdown"
[task 2026-02-28T13:44:03.621+00:00] 13:44:03     INFO - GECKO(30979) | 1772286243620	Marionette	INFO	Stopped listening on port 2828
[task 2026-02-28T13:44:03.816+00:00] 13:44:03     INFO - GECKO(30979) | 1772286243815	Marionette	DEBUG	Marionette stopped listening
[task 2026-02-28T13:44:04.906+00:00] 13:44:04     INFO - GECKO(30979) | 1772286244905	Marionette	TRACE	Received observer notification xpcom-shutdown
[task 2026-02-28T13:44:04.963+00:00] 13:44:04     INFO - GECKO(30979) | 1772286244961	Marionette	TRACE	Received observer notification xpcom-shutdown-threads
[task 2026-02-28T13:44:07.268+00:00] 13:44:07     INFO - TEST-INFO | Main app process: exit 0
[task 2026-02-28T13:44:07.268+00:00] 13:44:07     INFO - runtests.py | Application ran for: 0:00:26.106999
[task 2026-02-28T13:44:07.268+00:00] 13:44:07     INFO - zombiecheck | Reading PID log: /tmp/tmp1m6fvastpidlog
[task 2026-02-28T13:44:07.269+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31095
[task 2026-02-28T13:44:07.269+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31100
[task 2026-02-28T13:44:07.269+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31131
[task 2026-02-28T13:44:07.270+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31180
[task 2026-02-28T13:44:07.270+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31212
[task 2026-02-28T13:44:07.271+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31218
[task 2026-02-28T13:44:07.271+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31235
[task 2026-02-28T13:44:07.271+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31271
[task 2026-02-28T13:44:07.272+00:00] 13:44:07     INFO - ==> process 30979 launched child process 31344
[task 2026-02-28T13:44:07.272+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31235
[task 2026-02-28T13:44:07.273+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31271
[task 2026-02-28T13:44:07.273+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31212
[task 2026-02-28T13:44:07.273+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31180
[task 2026-02-28T13:44:07.274+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31344
[task 2026-02-28T13:44:07.274+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31218
[task 2026-02-28T13:44:07.275+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31095
[task 2026-02-28T13:44:07.275+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31131
[task 2026-02-28T13:44:07.275+00:00] 13:44:07     INFO - zombiecheck | Checking for orphan process with PID: 31100
[task 2026-02-28T13:44:07.276+00:00] 13:44:07     INFO - runtests.py | Running http tests: end. status: 0
[task 2026-02-28T13:44:07.276+00:00] 13:44:07     INFO - Stopping web server
[task 2026-02-28T13:44:07.276+00:00] 13:44:07     INFO - Server shut down.
[task 2026-02-28T13:44:07.277+00:00] 13:44:07     INFO - Web server killed.
[task 2026-02-28T13:44:07.277+00:00] 13:44:07     INFO - Stopping web socket server
[task 2026-02-28T13:44:07.277+00:00] 13:44:07     INFO - Stopping ssltunnel
[task 2026-02-28T13:44:07.278+00:00] 13:44:07     INFO - Stopping gst for v4l2loopback
[task 2026-02-28T13:44:07.278+00:00] 13:44:07  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2026-02-28T13:44:07.313+00:00] 13:44:07     INFO - Buffered messages finished
[task 2026-02-28T13:44:07.313+00:00] 13:44:07     INFO - Running manifest: dom/filesystem/tests/mochitest.toml
[task 2026-02-28T13:44:07.368+00:00] 13:44:07     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:44:07.380+00:00] 13:44:07     INFO -  Setting pipeline to PAUSED ...
[task 2026-02-28T13:44:07.381+00:00] 13:44:07     INFO -  Pipeline is PREROLLING ...
[task 2026-02-28T13:44:07.382+00:00] 13:44:07     INFO -  Pipeline is PREROLLED ...
[task 2026-02-28T13:44:07.382+00:00] 13:44:07     INFO -  Setting pipeline to PLAYING ...
[task 2026-02-28T13:44:07.382+00:00] 13:44:07     INFO -  Redistribute latency...
[task 2026-02-28T13:44:07.383+00:00] 13:44:07     INFO -  New clock: GstSystemClock
[task 2026-02-28T13:44:07.416+00:00] 13:44:07     INFO -  Got EOS from element "pipeline0".
[task 2026-02-28T13:44:07.416+00:00] 13:44:07     INFO -  Execution ended after 0:00:00.033501700
[task 2026-02-28T13:44:07.416+00:00] 13:44:07     INFO -  Setting pipeline to NULL ...
[task 2026-02-28T13:44:07.549+00:00] 13:44:07     INFO - PID 31421 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2026-02-28T13:44:07.549+00:00] 13:44:07     INFO - 
[task 2026-02-28T13:44:07.898+00:00] 13:44:07     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:44:07.898+00:00] 13:44:07     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:44:07.899+00:00] 13:44:07     INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-e', "const _PROFILE_PATH = '/tmp/tmpy0e0txl1.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false; const _HTTPD_PATH = '/builds/worker/workspace/build/tests/bin/components';", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2026-02-28T13:44:07.900+00:00] 13:44:07     INFO - runtests.py | Server pid: 31438
[task 2026-02-28T13:44:07.901+00:00] 13:44:07     INFO - runtests.py | Websocket server pid: 31439
[task 2026-02-28T13:44:07.901+00:00] 13:44:07     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2026-02-28T13:44:07.901+00:00] 13:44:07     INFO - runtests.py | SSL tunnel pid: 31440
[task 2026-02-28T13:44:08.201+00:00] 13:44:08     INFO - use http3 server: 0
[task 2026-02-28T13:44:08.203+00:00] 13:44:08     INFO - runtests.py | Running with scheme: http
[task 2026-02-28T13:44:08.203+00:00] 13:44:08     INFO - runtests.py | Running with e10s: True
[task 2026-02-28T13:44:08.203+00:00] 13:44:08     INFO - runtests.py | Running with fission: True
[task 2026-02-28T13:44:08.204+00:00] 13:44:08     INFO - runtests.py | Running with cross-origin iframes: False
[task 2026-02-28T13:44:08.204+00:00] 13:44:08     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2026-02-28T13:44:08.205+00:00] 13:44:08     INFO - runtests.py | Running http tests: start.
[task 2026-02-28T13:44:08.205+00:00] 13:44:08     INFO - 
[task 2026-02-28T13:44:08.207+00:00] 13:44:08     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -remote-allow-system-access -foreground -profile /tmp/tmpy0e0txl1.mozrunner
[task 2026-02-28T13:44:08.212+00:00] 13:44:08     INFO - runtests.py | Application pid: 31484
[task 2026-02-28T13:44:08.212+00:00] 13:44:08     INFO - TEST-INFO | started process GECKO(31484)
[task 2026-02-28T13:44:10.661+00:00] 13:44:10     INFO - GECKO(31484) | libEGL warning: DRI3: Screen seems not DRI3 capable
[task 2026-02-28T13:44:10.662+00:00] 13:44:10     INFO - GECKO(31484) | libEGL warning: DRI3: Screen seems not DRI3 capable
[task 2026-02-28T13:44:10.717+00:00] 13:44:10     INFO - GECKO(31484) | MESA: error: ZINK: failed to choose pdev
[task 2026-02-28T13:44:10.721+00:00] 13:44:10     INFO - GECKO(31484) | 1772286250720	Marionette	INFO	Marionette enabled
[task 2026-02-28T13:44:10.729+00:00] 13:44:10     INFO - GECKO(31484) | libEGL warning: egl: failed to create dri2 screen
[task 2026-02-28T13:44:10.729+00:00] 13:44:10     INFO - GECKO(31484) | 1772286250728	Marionette	TRACE	Received observer notification final-ui-startup
[task 2026-02-28T13:44:11.193+00:00] 13:44:11     INFO - GECKO(31484) | console.error: "Warning: unrecognized command line flag" "-foreground"
[task 2026-02-28T13:44:11.350+00:00] 13:44:11     INFO - GECKO(31484) | 1772286251349	Marionette	INFO	Listening on port 2828
[task 2026-02-28T13:44:11.361+00:00] 13:44:11     INFO - GECKO(31484) | 1772286251360	Marionette	DEBUG	Marionette is listening
[task 2026-02-28T13:44:11.453+00:00] 13:44:11     INFO - GECKO(31484) | 1772286251452	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:35414
[task 2026-02-28T13:44:11.522+00:00] 13:44:11     INFO - GECKO(31484) | 1772286251521	Marionette	DEBUG	Closed connection 0
[task 2026-02-28T13:44:11.996+00:00] 13:44:11     INFO - GECKO(31484) | 1772286251995	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:35418
[task 2026-02-28T13:44:12.121+00:00] 13:44:12     INFO - GECKO(31484) | 1772286252120	Marionette	DEBUG	Closed connection 1
[task 2026-02-28T13:44:12.122+00:00] 13:44:12     INFO - GECKO(31484) | 1772286252121	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:35432
[task 2026-02-28T13:44:12.656+00:00] 13:44:12     INFO - GECKO(31484) | 1772286252655	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2026-02-28T13:44:12.698+00:00] 13:44:12     INFO - GECKO(31484) | 1772286252697	Marionette	DEBUG	Waiting for initial application window
[task 2026-02-28T13:44:13.567+00:00] 13:44:13     INFO - GECKO(31484) | [Parent 31484: Main Thread]: I/SlowChromeEvent Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out! chrome://browser/content/tabbrowser/tabs.js:51:12
[task 2026-02-28T13:44:16.640+00:00] 13:44:16     INFO - GECKO(31484) | warning: address range table at offset 0x78970 has a premature terminator entry at offset 0x789c0
[task 2026-02-28T13:44:16.641+00:00] 13:44:16     INFO - GECKO(31484) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7cda0
[task 2026-02-28T13:44:16.641+00:00] 13:44:16     INFO - GECKO(31484) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7cde0
[task 2026-02-28T13:44:16.642+00:00] 13:44:16     INFO - GECKO(31484) | warning: address range table at offset 0x7cc20 has a premature terminator entry at offset 0x7ce90
[taskcluster:error] Aborting task...
[taskcluster 2026-02-28T13:44:16.927Z] Command ABORTED after 1h0m0.000904155s: process aborted
[taskcluster 2026-02-28T13:44:16.927Z]  Average Available System Memory: 27.04 GiB
[taskcluster 2026-02-28T13:44:16.927Z]       Average System Memory Used: 4.30 GiB
[taskcluster 2026-02-28T13:44:16.927Z]          Peak System Memory Used: 9.18 GiB
[taskcluster 2026-02-28T13:44:16.927Z]              Total System Memory: 31.34 GiB
[taskcluster 2026-02-28T13:44:16.927Z] 
[taskcluster 2026-02-28T13:44:16.927Z] === Task Finished ===
[taskcluster 2026-02-28T13:44:16.927Z] Task Duration: 1h0m0.001232425s
[taskcluster 2026-02-28T13:44:19.337Z] [mounts] Preserving cache: Moving "/home/task_177228240272711/cache0" to "/home/generic-worker/caches/R5DeY7msQXe-1LYfZ3u6ug"
[taskcluster 2026-02-28T13:44:19.337Z] [mounts] Preserving cache: Moving "/home/task_177228240272711/cache1" to "/home/generic-worker/caches/RMwErMNWQx-tHhVdjYwKSg"
[taskcluster 2026-02-28T13:44:19.337Z] [mounts] Preserving cache: Moving "/home/task_177228240272711/cache2" to "/home/generic-worker/caches/Tw9OdY4TTpGpD7d8sYaeqw"
[taskcluster:error] task aborted - max run time exceeded

This has permafailed on this push, oddly backfills do not work for this job, and this job does not have "Test Groups"

Summary: Perma mochitest [taskcluster:error] Aborting task... | single tracking bug → Perma mochitest plain [taskcluster:error] Aborting task... | single tracking bug

(In reply to Serban Stanca [:SerbanS] from comment #41)

Hi Andrew! Could you please check this? Lately there were some perma mochitests plain failures on Android 14.0 x86-64 Lite opt: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&fromchange=8c5db93095b20fc4097f313887433d092b056e64&searchStr=android%2C14.0%2Cx86-64%2Clite%2Copt%2Cmochitests%2Cwith%2Ccross-origin%2Ctest-android-em-14-x86_64-lite%2Fopt-geckoview-mochitest-plain-xorig%2C1&selectedTaskRun=TM4d32z8TIeHAVZA87vRhQ.0.

Do you have any idea about what could have caused it?

Thank you!

I took a look at this. The selected task hit its 3600s max runtime; it wasn't failing a specific mochitest. It started at 00:13:09, was still starting tests at 01:13:10, and was killed at 01:13:23.

It looks like this job was scheduled as one chunk, even though the Android Nightly xorigin jobs are split into 5 chunks. The job has dynamic chunking enabled, but it seems the runtime data made it choose one chunk here.

This started shortly after dynamic chunking was enabled for mochitest-plain in bug 2017946, so I wonder if the timing data for this configuration is incomplete or otherwise underestimating the runtime.

Florian, could you take a look at the timing-data side? Do you know why this task would have been assigned one chunk?

Flags: needinfo?(aerickson) → needinfo?(florian)
You need to log in before you can comment on or make changes to this bug.