Closed Bug 1800024 Opened 2 years ago Closed 3 months ago

Intermittent /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html | single tracking bug

Categories

(Core :: Storage: IndexedDB, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox-esr102 --- unaffected
firefox106 --- unaffected
firefox107 --- unaffected
firefox108 --- wontfix
firefox109 --- wontfix
firefox110 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug, Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [stockwell unknown])

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


[task 2022-11-10T03:17:17.951Z] 03:17:17     INFO - TEST-START | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html
[task 2022-11-10T03:17:17.998Z] 03:17:17     INFO - Setting pref dom.fs.enabled to true
[task 2022-11-10T03:17:28.373Z] 03:17:28     INFO - 
[task 2022-11-10T03:17:28.373Z] 03:17:28     INFO - TEST-FAIL | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.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-10T03:17:28.374Z] 03:17:28     INFO - TEST-FAIL | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.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-10T03:17:28.374Z] 03:17:28     INFO - TEST-UNEXPECTED-TIMEOUT | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html | Store handles and blobs in IndexedDB. - Test timed out
[task 2022-11-10T03:17:28.374Z] 03:17:28     INFO - TEST-INFO | expected FAIL
[task 2022-11-10T03:17:28.375Z] 03:17:28     INFO - 
[task 2022-11-10T03:17:28.375Z] 03:17:28     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html | Store handle in IndexedDB and read using a cursor. - expected FAIL
[task 2022-11-10T03:17:28.375Z] 03:17:28     INFO - TEST-INFO | expected FAIL
[task 2022-11-10T03:17:28.377Z] 03:17:28     INFO - 
[task 2022-11-10T03:17:28.377Z] 03:17:28     INFO - TEST-UNEXPECTED-NOTRUN | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html | Store handle in IndexedDB using inline keys. - expected FAIL
[task 2022-11-10T03:17:28.377Z] 03:17:28     INFO - TEST-INFO | expected FAIL
[task 2022-11-10T03:17:28.378Z] 03:17:28     INFO - TEST-UNEXPECTED-TIMEOUT | /fs/FileSystemBaseHandle-IndexedDB.https.any.worker.html | expected OK
[task 2022-11-10T03:17:28.378Z] 03:17:28     INFO - TEST-INFO took 10420ms
[task 2022-11-10T03:17:28.380Z] 03:17:28     INFO - PID 1704 | 1668050248374	Marionette	INFO	Stopped listening on port 52646
[task 2022-11-10T03:17:29.392Z] 03:17:29     INFO - PID 1704 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-10T03:17:29.398Z] 03:17:29     INFO - PID 1704 |           Blocker:  Waiting for ping task
[task 2022-11-10T03:17:29.399Z] 03:17:29     INFO - PID 1704 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-10T03:17:29.400Z] 03:17:29     INFO - PID 1704 |           State: (none)
[task 2022-11-10T03:17:29.401Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.401Z] 03:17:29     INFO - PID 1704 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-10T03:17:29.402Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-10T03:17:29.403Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-10T03:17:29.404Z] 03:17:29     INFO - PID 1704 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-10T03:17:29.405Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-10T03:17:29.405Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-10T03:17:29.406Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-10T03:17:29.406Z] 03:17:29     INFO - PID 1704 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-10T03:17:29.408Z] 03:17:29     INFO - PID 1704 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-10T03:17:29.408Z] 03:17:29     INFO - PID 1704 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-10T03:17:29.409Z] 03:17:29     INFO - PID 1704 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-10T03:17:29.409Z] 03:17:29     INFO - PID 1704 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-10T03:17:29.410Z] 03:17:29     INFO - PID 1704 | sendPing@resource://gre/modules/EventPing.jsm:51:30
[task 2022-11-10T03:17:29.411Z] 03:17:29     INFO - PID 1704 | _submitPing@resource://gre/modules/EventPing.jsm:229:12
[task 2022-11-10T03:17:29.412Z] 03:17:29     INFO - PID 1704 | shutdown@resource://gre/modules/EventPing.jsm:112:10
[task 2022-11-10T03:17:29.412Z] 03:17:29     INFO - PID 1704 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:954:31
[task 2022-11-10T03:17:29.413Z] 03:17:29     INFO - PID 1704 | shutdown/<@resource://gre/modules/TelemetryControllerParent.jsm:1024:24
[task 2022-11-10T03:17:29.413Z] 03:17:29     INFO - PID 1704 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-10T03:17:29.416Z] 03:17:29     INFO - PID 1704 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-10T03:17:29.417Z] 03:17:29     INFO - PID 1704 |           Blocker:  Waiting for ping task
[task 2022-11-10T03:17:29.418Z] 03:17:29     INFO - PID 1704 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-10T03:17:29.418Z] 03:17:29     INFO - PID 1704 |           State: (none)
[task 2022-11-10T03:17:29.419Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.420Z] 03:17:29     INFO - PID 1704 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-10T03:17:29.421Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-10T03:17:29.422Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-10T03:17:29.422Z] 03:17:29     INFO - PID 1704 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-10T03:17:29.423Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-10T03:17:29.424Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-10T03:17:29.425Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-10T03:17:29.426Z] 03:17:29     INFO - PID 1704 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-10T03:17:29.427Z] 03:17:29     INFO - PID 1704 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-10T03:17:29.428Z] 03:17:29     INFO - PID 1704 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-10T03:17:29.428Z] 03:17:29     INFO - PID 1704 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-10T03:17:29.429Z] 03:17:29     INFO - PID 1704 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-10T03:17:29.429Z] 03:17:29     INFO - PID 1704 | saveShutdownPings@resource://gre/modules/TelemetrySession.jsm:982:34
[task 2022-11-10T03:17:29.431Z] 03:17:29     INFO - PID 1704 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1232:20
[task 2022-11-10T03:17:29.432Z] 03:17:29     INFO - PID 1704 | cleanup@resource://gre/modules/TelemetrySession.jsm:1239:9
[task 2022-11-10T03:17:29.432Z] 03:17:29     INFO - PID 1704 | shutdownChromeProcess@resource://gre/modules/TelemetrySession.jsm:1256:14
[task 2022-11-10T03:17:29.433Z] 03:17:29     INFO - PID 1704 | shutdown@resource://gre/modules/TelemetrySession.jsm:247:17
[task 2022-11-10T03:17:29.434Z] 03:17:29     INFO - PID 1704 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:973:35
[task 2022-11-10T03:17:29.435Z] 03:17:29     INFO - PID 1704 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-10T03:17:29.436Z] 03:17:29     INFO - PID 1704 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-10T03:17:29.437Z] 03:17:29     INFO - PID 1704 |           Blocker:  TelemetryController: shutting down
[task 2022-11-10T03:17:29.438Z] 03:17:29     INFO - PID 1704 |           Phase: profile-before-change-telemetry
[task 2022-11-10T03:17:29.438Z] 03:17:29     INFO - PID 1704 |           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-10T03:17:29.440Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-10T03:17:29.440Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-10T03:17:29.441Z] 03:17:29     INFO - PID 1704 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-10T03:17:29.442Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-10T03:17:29.443Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-10T03:17:29.444Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-10T03:17:29.445Z] 03:17:29     INFO - PID 1704 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:1687:7
[task 2022-11-10T03:17:29.445Z] 03:17:29     INFO - PID 1704 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:369:30
[task 2022-11-10T03:17:29.446Z] 03:17:29     INFO - PID 1704 | _getState@resource://gre/modules/TelemetryControllerParent.jsm:1072:38
[task 2022-11-10T03:17:29.447Z] 03:17:29     INFO - PID 1704 | setupTelemetry/<@resource://gre/modules/TelemetryControllerParent.jsm:931:18
[task 2022-11-10T03:17:29.448Z] 03:17:29     INFO - PID 1704 | safeGetState@resource://gre/modules/AsyncShutdown.jsm:242:17
[task 2022-11-10T03:17:29.449Z] 03:17:29     INFO - PID 1704 | Barrier/addBlocker/promise<@resource://gre/modules/AsyncShutdown.jsm:751:20
[task 2022-11-10T03:17:29.449Z] 03:17:29     INFO - PID 1704 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-10T03:17:29.450Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.451Z] 03:17:29     INFO - PID 1704 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-10T03:17:29.452Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-10T03:17:29.453Z] 03:17:29     INFO - PID 1704 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-10T03:17:29.454Z] 03:17:29     INFO - PID 1704 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-10T03:17:29.455Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-10T03:17:29.456Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-10T03:17:29.456Z] 03:17:29     INFO - PID 1704 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-10T03:17:29.457Z] 03:17:29     INFO - PID 1704 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:735:5
[task 2022-11-10T03:17:29.458Z] 03:17:29     INFO - PID 1704 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:249:17
[task 2022-11-10T03:17:29.458Z] 03:17:29     INFO - PID 1704 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1235:42
[task 2022-11-10T03:17:29.460Z] 03:17:29     INFO - PID 1704 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-10T03:17:29.501Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.503Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.504Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.505Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.506Z] 03:17:29     INFO - PID 1704 | 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-10T03:17:29.548Z] 03:17:29     INFO - Browser exited with return code 0
[task 2022-11-10T03:17:29.553Z] 03:17:29     INFO - Closing logging queue
[task 2022-11-10T03:17:29.554Z] 03:17:29     INFO - queue closed
[task 2022-11-10T03:17:29.596Z] 03:17:29     INFO - Application command: Z:\task_166804021695642\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_166804021695642\AppData\Local\Temp\tmp983wh8e1
[task 2022-11-10T03:17:29.601Z] 03:17:29     INFO - PID 9208 | 1668050236293	Marionette	INFO	Marionette enabled
[task 2022-11-10T03:17:29.602Z] 03:17:29     INFO - PID 9208 | 1668050236299	Marionette	INFO	Listening on port 52665
[task 2022-11-10T03:17:29.603Z] 03:17:29     INFO - PID 9208 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_166804021695642\\AppData\\Local\\Temp\\tmpqbc7gxut\\search.json.mozlz4", (void 0)))
[task 2022-11-10T03:17:29.604Z] 03:17:29     INFO - PID 9208 | *** You are running in background task mode. ***
[task 2022-11-10T03:17:29.605Z] 03:17:29     INFO - PID 9208 | *** You are running in headless mode.
[task 2022-11-10T03:17:29.605Z] 03:17:29     INFO - PID 9208 | console.error: "C:\\Users\\task_166804021695642\\AppData\\Local\\Temp\\tmpqbc7gxut" "" 0 ".purge.bg_rm"
[task 2022-11-10T03:17:29.606Z] 03:17:29     INFO - Starting runner
[task 2022-11-10T03:17:30.703Z] 03:17:30     INFO - TEST-START | /fs/FileSystemBaseHandle-IndexedDB.https.any.html
See Also: → 1800025

:jesup, since you are the author of the regressor, bug 1777361, could you take a look?

For more information, please visit auto_nag documentation.

Flags: needinfo?(rjesup)

There have been 31 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
Whiteboard: [stockwell needswork:owner]

There have been 36 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-ccov-qr
  • windows10-64-2004-qr
  • windows10-64-2004-shippable-qr

Jari, could you please take a look what needs to be done here and in case it's a known issue set the right dependencies?

Flags: needinfo?(rjesup) → needinfo?(jjalkanen)

These failures occure because our CI is at times under heavy load and tests don't get executed due to unresponsive disk or network, and terminate with status TIMEOUT or NOTRUN.

To resolve this, we should add the missing outcome TIMEOUT or NOTRUN to all the tests with one but not both of these outcomes in testing/web-platform/meta/fs/FileSystemBaseHandle-IndexedDB.https.any.js.ini.

Flags: needinfo?(jjalkanen)
Depends on: 1834953
Status: NEW → RESOLVED
Closed: 10 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 10 months ago9 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 9 months ago6 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 months ago3 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.