1820002 - Intermittent /IndexedDB/idb_webworkers.htm | single tracking bug

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

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

---

INFO - TEST-START | /IndexedDB/idb_webworkers.htm
[task 2023-03-02T18:35:08.466Z] 18:35:08     INFO - Closing window 89f6af4e-0d33-454f-b949-8978e776c24d
[task 2023-03-02T18:35:19.122Z] 18:35:19     INFO - 
[task 2023-03-02T18:35:19.122Z] 18:35:19     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/idb_webworkers.htm | IndexedDB inside of a WebWorker  - Test timed out
[task 2023-03-02T18:35:19.125Z] 18:35:19     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/idb_webworkers.htm | expected OK
[task 2023-03-02T18:35:19.125Z] 18:35:19     INFO - TEST-INFO took 10678ms
[task 2023-03-02T18:35:19.127Z] 18:35:19     INFO - PID 7276 | 1677782119126	Marionette	INFO	Stopped listening on port 49899
[task 2023-03-02T18:35:24.498Z] 18:35:24     INFO - PID 7276 | console.error: "DEPRECATION WARNING: Calling FileUtils.getDir(..., ..., true) causes main thread I/O and should be avoided especially during startup/shutdown\nYou may find more details about this deprecation at: https://bugzilla.mozilla.org/show_bug.cgi?id=921157\nresource://gre/modules/FileUtils.sys.mjs 62 FileUtils_getDir\nresource://gre/modules/UpdateService.jsm 1065 getUpdateDirCreate\nresource://gre/modules/UpdateService.jsm 1104 getUpdateFile\nresource://gre/modules/UpdateService.jsm 4457 UM__loadXMLFileIntoArray\nresource://gre/modules/UpdateService.jsm 4291 UpdateManager\nresource://gre/modules/XPCOMUtils.sys.mjs 150 defineLazyServiceGetter/<\nresource://gre/modules/XPCOMUtils.sys.mjs 54 get\nresource://gre/modules/UpdateService.jsm 3390 get _pingSuffix\nresource://gre/modules/UpdateService.jsm 3423 AUS__checkForBackgroundUpdates\nresource://gre/modules/UpdateService.jsm 3378 AUS_notify\nresource://gre/modules/UpdateTimerManager.jsm 230 TM_notify/<\nresource://gre/modules/UpdateTimerManager.jsm 312 TM_notify\n"
[task 2023-03-02T18:35:29.350Z] 18:35:29     INFO - PID 7276 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-02T18:35:29.352Z] 18:35:29     INFO - PID 7276 |           Blocker:  Waiting for ping task
[task 2023-03-02T18:35:29.352Z] 18:35:29     INFO - PID 7276 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-02T18:35:29.353Z] 18:35:29     INFO - PID 7276 |           State: (none)
[task 2023-03-02T18:35:29.354Z] 18:35:29     INFO - PID 7276 | 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-03-02T18:35:29.354Z] 18:35:29     INFO - PID 7276 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-02T18:35:29.355Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-02T18:35:29.355Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-02T18:35:29.356Z] 18:35:29     INFO - PID 7276 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-02T18:35:29.356Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-02T18:35:29.357Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-02T18:35:29.358Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-02T18:35:29.358Z] 18:35:29     INFO - PID 7276 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-02T18:35:29.358Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-02T18:35:29.359Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-02T18:35:29.360Z] 18:35:29     INFO - PID 7276 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-02T18:35:29.360Z] 18:35:29     INFO - PID 7276 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-02T18:35:29.361Z] 18:35:29     INFO - PID 7276 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-02T18:35:29.365Z] 18:35:29     INFO - PID 7276 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-02T18:35:29.366Z] 18:35:29     INFO - PID 7276 |           Blocker:  Waiting for ping task
[task 2023-03-02T18:35:29.366Z] 18:35:29     INFO - PID 7276 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-02T18:35:29.367Z] 18:35:29     INFO - PID 7276 |           State: (none)
[task 2023-03-02T18:35:29.368Z] 18:35:29     INFO - PID 7276 | 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-03-02T18:35:29.368Z] 18:35:29     INFO - PID 7276 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-02T18:35:29.369Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-02T18:35:29.369Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-02T18:35:29.370Z] 18:35:29     INFO - PID 7276 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-02T18:35:29.370Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-02T18:35:29.371Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-02T18:35:29.372Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-02T18:35:29.373Z] 18:35:29     INFO - PID 7276 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-02T18:35:29.374Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-02T18:35:29.374Z] 18:35:29     INFO - PID 7276 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-02T18:35:29.375Z] 18:35:29     INFO - PID 7276 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-02T18:35:29.375Z] 18:35:29     INFO - PID 7276 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-02T18:35:29.376Z] 18:35:29     INFO - PID 7276 |           Blocker:  TelemetryController: shutting down
[task 2023-03-02T18:35:29.376Z] 18:35:29     INFO - PID 7276 |           Phase: profile-before-change-telemetry
[task 2023-03-02T18:35:29.377Z] 18:35:29     INFO - PID 7276 |           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.sys.mjs:727:15
[task 2023-03-02T18:35:29.377Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-02T18:35:29.378Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-02T18:35:29.378Z] 18:35:29     INFO - PID 7276 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-02T18:35:29.379Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-02T18:35:29.379Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-02T18:35:29.380Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-02T18:35:29.380Z] 18:35:29     INFO - PID 7276 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-02T18:35:29.380Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-02T18:35:29.381Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-02T18:35:29.381Z] 18:35:29     INFO - PID 7276 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-02T18:35:29.383Z] 18:35:29     INFO - PID 7276 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-02T18:35:29.383Z] 18:35:29     INFO - PID 7276 | 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-03-02T18:35:29.383Z] 18:35:29     INFO - PID 7276 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-02T18:35:29.384Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-02T18:35:29.384Z] 18:35:29     INFO - PID 7276 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-02T18:35:29.385Z] 18:35:29     INFO - PID 7276 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-02T18:35:29.385Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-02T18:35:29.385Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-02T18:35:29.386Z] 18:35:29     INFO - PID 7276 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-02T18:35:29.387Z] 18:35:29     INFO - PID 7276 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-02T18:35:29.387Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-02T18:35:29.388Z] 18:35:29     INFO - PID 7276 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-02T18:35:29.388Z] 18:35:29     INFO - PID 7276 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-02T18:35:29.389Z] 18:35:29     INFO - PID 7276 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-02T18:35:30.350Z] 18:35:30     INFO - PID 7276 | 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-03-02T18:35:30.355Z] 18:35:30     INFO - PID 7276 | 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-03-02T18:35:30.356Z] 18:35:30     INFO - PID 7276 | 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-03-02T18:35:30.357Z] 18:35:30     INFO - PID 7276 | 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-03-02T18:35:30.358Z] 18:35:30     INFO - PID 7276 | 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-03-02T18:35:30.416Z] 18:35:30     INFO - Browser exited with return code 0
<...>

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-32-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820002&startday=2023-02-27&endday=2023-03-05&tree=all

Comment 2

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

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

Comment 3

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=445226330&repo=mozilla-beta

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820002&startday=2024-01-29&endday=2024-02-04&tree=all

Comment 6

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

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