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

[task 2022-11-09T14:06:54.260Z] 14:06:54     INFO - TEST-START | /fs/FileSystemBaseHandle-IndexedDB.https.any.html
[task 2022-11-09T14:06:54.271Z] 14:06:54     INFO - Setting pref dom.fs.enabled to true
[task 2022-11-09T14:07:04.451Z] 14:07:04     INFO - 
[task 2022-11-09T14:07:04.451Z] 14:07:04     INFO - TEST-FAIL | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read from pending transaction. - promise_test: Unhandled rejection with value: object "[Exception... "Method not implemented"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: https://web-platform.test:8443/fs/resources/test-helpers.js :: createFileWithContents :: line 77"  data: no]"
[task 2022-11-09T14:07:04.451Z] 14:07:04     INFO - TEST-FAIL | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read from new transaction. - promise_test: Unhandled rejection with value: object "[Exception... "Method not implemented"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: https://web-platform.test:8443/fs/resources/test-helpers.js :: createFileWithContents :: line 77"  data: no]"
[task 2022-11-09T14:07:04.452Z] 14:07:04     INFO - TEST-FAIL | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handles and blobs in IndexedDB. - promise_test: Unhandled rejection with value: object "[Exception... "Method not implemented"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: https://web-platform.test:8443/fs/resources/test-helpers.js :: createFileWithContents :: line 77"  data: no]"
[task 2022-11-09T14:07:04.452Z] 14:07:04     INFO - TEST-UNEXPECTED-TIMEOUT | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read using a cursor. - Test timed out
[task 2022-11-09T14:07:04.452Z] 14:07:04     INFO - TEST-INFO | expected FAIL
[task 2022-11-09T14:07:04.453Z] 14:07:04     INFO - 
[task 2022-11-09T14:07:04.453Z] 14:07:04     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB using inline keys. - expected FAIL
[task 2022-11-09T14:07:04.453Z] 14:07:04     INFO - TEST-INFO | expected FAIL
[task 2022-11-09T14:07:04.454Z] 14:07:04     INFO - TEST-UNEXPECTED-TIMEOUT | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | expected OK
[task 2022-11-09T14:07:04.454Z] 14:07:04     INFO - TEST-INFO took 10183ms
[task 2022-11-09T14:07:04.456Z] 14:07:04     INFO - PID 3504 | 1668002824450	Marionette	INFO	Stopped listening on port 61565
[task 2022-11-09T14:07:05.418Z] 14:07:05     INFO - PID 3504 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-09T14:07:05.419Z] 14:07:05     INFO - PID 3504 |           Blocker:  Waiting for ping task
[task 2022-11-09T14:07:05.420Z] 14:07:05     INFO - PID 3504 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-09T14:07:05.420Z] 14:07:05     INFO - PID 3504 |           State: (none)
[task 2022-11-09T14:07:05.421Z] 14:07:05     INFO - PID 3504 | 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 2022-11-09T14:07:05.421Z] 14:07:05     INFO - PID 3504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-09T14:07:05.422Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-09T14:07:05.423Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-09T14:07:05.424Z] 14:07:05     INFO - PID 3504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-09T14:07:05.424Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-09T14:07:05.425Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-09T14:07:05.425Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-09T14:07:05.426Z] 14:07:05     INFO - PID 3504 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-09T14:07:05.426Z] 14:07:05     INFO - PID 3504 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-09T14:07:05.427Z] 14:07:05     INFO - PID 3504 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-09T14:07:05.427Z] 14:07:05     INFO - PID 3504 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-09T14:07:05.428Z] 14:07:05     INFO - PID 3504 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-09T14:07:05.428Z] 14:07:05     INFO - PID 3504 | sendPing@resource://gre/modules/EventPing.jsm:51:30
[task 2022-11-09T14:07:05.429Z] 14:07:05     INFO - PID 3504 | _submitPing@resource://gre/modules/EventPing.jsm:229:12
[task 2022-11-09T14:07:05.429Z] 14:07:05     INFO - PID 3504 | shutdown@resource://gre/modules/EventPing.jsm:112:10
[task 2022-11-09T14:07:05.430Z] 14:07:05     INFO - PID 3504 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:954:31
[task 2022-11-09T14:07:05.431Z] 14:07:05     INFO - PID 3504 | shutdown/<@resource://gre/modules/TelemetryControllerParent.jsm:1024:24
[task 2022-11-09T14:07:05.431Z] 14:07:05     INFO - PID 3504 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-09T14:07:05.433Z] 14:07:05     INFO - PID 3504 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-09T14:07:05.433Z] 14:07:05     INFO - PID 3504 |           Blocker:  Waiting for ping task
[task 2022-11-09T14:07:05.434Z] 14:07:05     INFO - PID 3504 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-09T14:07:05.434Z] 14:07:05     INFO - PID 3504 |           State: (none)
[task 2022-11-09T14:07:05.435Z] 14:07:05     INFO - PID 3504 | 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 2022-11-09T14:07:05.435Z] 14:07:05     INFO - PID 3504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-09T14:07:05.436Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-09T14:07:05.437Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-09T14:07:05.437Z] 14:07:05     INFO - PID 3504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-09T14:07:05.438Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-09T14:07:05.439Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-09T14:07:05.439Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-09T14:07:05.440Z] 14:07:05     INFO - PID 3504 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-09T14:07:05.440Z] 14:07:05     INFO - PID 3504 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-09T14:07:05.441Z] 14:07:05     INFO - PID 3504 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-09T14:07:05.441Z] 14:07:05     INFO - PID 3504 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-09T14:07:05.442Z] 14:07:05     INFO - PID 3504 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-09T14:07:05.442Z] 14:07:05     INFO - PID 3504 | saveShutdownPings@resource://gre/modules/TelemetrySession.jsm:982:34
[task 2022-11-09T14:07:05.443Z] 14:07:05     INFO - PID 3504 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1232:20
[task 2022-11-09T14:07:05.443Z] 14:07:05     INFO - PID 3504 | cleanup@resource://gre/modules/TelemetrySession.jsm:1239:9
[task 2022-11-09T14:07:05.444Z] 14:07:05     INFO - PID 3504 | shutdownChromeProcess@resource://gre/modules/TelemetrySession.jsm:1256:14
[task 2022-11-09T14:07:05.445Z] 14:07:05     INFO - PID 3504 | shutdown@resource://gre/modules/TelemetrySession.jsm:247:17
[task 2022-11-09T14:07:05.446Z] 14:07:05     INFO - PID 3504 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:973:35
[task 2022-11-09T14:07:05.446Z] 14:07:05     INFO - PID 3504 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-09T14:07:05.447Z] 14:07:05     INFO - PID 3504 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-09T14:07:05.447Z] 14:07:05     INFO - PID 3504 |           Blocker:  TelemetryController: shutting down
[task 2022-11-09T14:07:05.447Z] 14:07:05     INFO - PID 3504 |           Phase: profile-before-change-telemetry
[task 2022-11-09T14:07:05.449Z] 14:07:05     INFO - PID 3504 |           State: Error getting state: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange" at addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-09T14:07:05.449Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-09T14:07:05.449Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-09T14:07:05.450Z] 14:07:05     INFO - PID 3504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-09T14:07:05.450Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-09T14:07:05.451Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-09T14:07:05.451Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-09T14:07:05.452Z] 14:07:05     INFO - PID 3504 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:1687:7
[task 2022-11-09T14:07:05.452Z] 14:07:05     INFO - PID 3504 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:369:30
[task 2022-11-09T14:07:05.453Z] 14:07:05     INFO - PID 3504 | _getState@resource://gre/modules/TelemetryControllerParent.jsm:1072:38
[task 2022-11-09T14:07:05.453Z] 14:07:05     INFO - PID 3504 | setupTelemetry/<@resource://gre/modules/TelemetryControllerParent.jsm:931:18
[task 2022-11-09T14:07:05.453Z] 14:07:05     INFO - PID 3504 | safeGetState@resource://gre/modules/AsyncShutdown.jsm:242:17
[task 2022-11-09T14:07:05.454Z] 14:07:05     INFO - PID 3504 | Barrier/addBlocker/promise<@resource://gre/modules/AsyncShutdown.jsm:751:20
[task 2022-11-09T14:07:05.455Z] 14:07:05     INFO - PID 3504 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-09T14:07:05.456Z] 14:07:05     INFO - PID 3504 | 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 2022-11-09T14:07:05.456Z] 14:07:05     INFO - PID 3504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-09T14:07:05.456Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-09T14:07:05.457Z] 14:07:05     INFO - PID 3504 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-09T14:07:05.457Z] 14:07:05     INFO - PID 3504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-09T14:07:05.458Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-09T14:07:05.458Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-09T14:07:05.458Z] 14:07:05     INFO - PID 3504 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-09T14:07:05.459Z] 14:07:05     INFO - PID 3504 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:735:5
[task 2022-11-09T14:07:05.460Z] 14:07:05     INFO - PID 3504 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:249:17
[task 2022-11-09T14:07:05.460Z] 14:07:05     INFO - PID 3504 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1235:42
[task 2022-11-09T14:07:05.461Z] 14:07:05     INFO - PID 3504 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-09T14:07:05.492Z] 14:07:05     INFO - PID 3504 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-09T14:07:05.497Z] 14:07:05     INFO - PID 3504 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-09T14:07:05.498Z] 14:07:05     INFO - PID 3504 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-09T14:07:05.499Z] 14:07:05     INFO - PID 3504 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-09T14:07:05.500Z] 14:07:05     INFO - PID 3504 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-09T14:07:05.540Z] 14:07:05     INFO - Browser exited with return code 0
[task 2022-11-09T14:07:05.544Z] 14:07:05     INFO - Closing logging queue
[task 2022-11-09T14:07:05.544Z] 14:07:05     INFO - queue closed
[task 2022-11-09T14:07:05.573Z] 14:07:05     INFO - Application command: Z:\task_166799545401607\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_166799545401607\AppData\Local\Temp\tmpw3janrh2
[task 2022-11-09T14:07:05.585Z] 14:07:05     INFO - PID 8768 | 1668002813662	Marionette	INFO	Marionette enabled
[task 2022-11-09T14:07:05.585Z] 14:07:05     INFO - PID 8768 | 1668002813664	Marionette	INFO	Listening on port 61614
[task 2022-11-09T14:07:05.586Z] 14:07:05     INFO - PID 8768 | JavaScript error: resource://gre/modules/XULStore.jsm, line 58: Error: Can't find profile directory.
[task 2022-11-09T14:07:05.586Z] 14:07:05     INFO - PID 8768 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_166799545401607\\AppData\\Local\\Temp\\tmpluv1jecd\\search.json.mozlz4", (void 0)))
[task 2022-11-09T14:07:05.587Z] 14:07:05     INFO - Starting runner
[task 2022-11-09T14:07:06.508Z] 14:07:06     INFO - TEST-START | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html

There have been 32 total failures in the last 7 days, recent failure log.
Affected platforms are:

• windows10-32-2004-qr
• windows10-32-2004-shippable-qr
• windows10-64-2004-qr
• windows10-64-2004-shippable-qr

[task 2023-01-04T20:26:13.852Z] 20:26:13     INFO - TEST-PASS | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read from pending transaction. 
[task 2023-01-04T20:26:13.853Z] 20:26:13     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read from new transaction. - expected PASS
[task 2023-01-04T20:26:13.854Z] 20:26:13     INFO - 
[task 2023-01-04T20:26:13.854Z] 20:26:13     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handles and blobs in IndexedDB. - expected PASS
[task 2023-01-04T20:26:13.855Z] 20:26:13     INFO - 
[task 2023-01-04T20:26:13.855Z] 20:26:13     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB and read using a cursor. - expected PASS
[task 2023-01-04T20:26:13.856Z] 20:26:13     INFO - 
[task 2023-01-04T20:26:13.856Z] 20:26:13     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Store handle in IndexedDB using inline keys. - expected PASS
[task 2023-01-04T20:26:13.858Z] 20:26:13     INFO - TEST-UNEXPECTED-ERROR | /fs/FileSystemBaseHandle-IndexedDB.https.any.html | Timeout while running cleanup for test named "Store handle in IndexedDB and read from pending transaction.".
[task 2023-01-04T20:26:13.858Z] 20:26:13     INFO - TEST-INFO took 10508ms