Closed Bug 1823203 Opened 3 years ago Closed 3 years ago

Intermittent /IndexedDB/idbobjectstore_add5.htm | single tracking bug

Categories

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

Product:
Core
Component:
Storage: IndexedDB
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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

[task 2023-03-19T07:49:53.482Z] 07:49:53     INFO - TEST-START | /IndexedDB/idbobjectstore_add5.htm
[task 2023-03-19T07:49:53.486Z] 07:49:53     INFO - Closing window 0c6aa978-f8b7-4cb5-b043-9c3d5f5edfb9
[task 2023-03-19T07:50:03.582Z] 07:50:03     INFO - 
[task 2023-03-19T07:50:03.582Z] 07:50:03     INFO - TEST-UNEXPECTED-NOTRUN | /IndexedDB/idbobjectstore_add5.htm | IDBObjectStore.add() - object store's key path is an object attribute  - expected PASS
[task 2023-03-19T07:50:03.590Z] 07:50:03     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/idbobjectstore_add5.htm | expected OK
[task 2023-03-19T07:50:03.590Z] 07:50:03     INFO - TEST-INFO took 10113ms
[task 2023-03-19T07:50:03.593Z] 07:50:03     INFO - PID 2256 | 1679212203592	Marionette	INFO	Stopped listening on port 49542
[task 2023-03-19T07:50:18.677Z] 07:50:18     INFO - PID 2256 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.sys.mjs", 370))
[task 2023-03-19T07:50:26.665Z] 07:50:26     INFO - PID 2256 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Places Connection shutdown","state":{"PlacesShutdownProgress":5},"filename":"/builds/worker/checkouts/gecko/toolkit/components/places/Database.cpp","lineNumber":470,"stack":""}] Barrier: profile-before-change
[task 2023-03-19T07:50:33.223Z] 07:50:33     INFO - PID 2256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-19T07:50:33.239Z] 07:50:33     INFO - PID 2256 |           Blocker:  Waiting for ping task
[task 2023-03-19T07:50:33.239Z] 07:50:33     INFO - PID 2256 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-19T07:50:33.240Z] 07:50:33     INFO - PID 2256 |           State: (none)
[task 2023-03-19T07:50:33.240Z] 07:50:33     INFO - PID 2256 | 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-19T07:50:33.241Z] 07:50:33     INFO - PID 2256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-19T07:50:33.242Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-19T07:50:33.243Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-19T07:50:33.243Z] 07:50:33     INFO - PID 2256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-19T07:50:33.244Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-19T07:50:33.244Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-19T07:50:33.245Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-19T07:50:33.245Z] 07:50:33     INFO - PID 2256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-19T07:50:33.245Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-19T07:50:33.246Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-19T07:50:33.246Z] 07:50:33     INFO - PID 2256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-19T07:50:33.247Z] 07:50:33     INFO - PID 2256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-19T07:50:33.247Z] 07:50:33     INFO - PID 2256 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-19T07:50:33.270Z] 07:50:33     INFO - PID 2256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-19T07:50:33.271Z] 07:50:33     INFO - PID 2256 |           Blocker:  Waiting for ping task
[task 2023-03-19T07:50:33.272Z] 07:50:33     INFO - PID 2256 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-19T07:50:33.272Z] 07:50:33     INFO - PID 2256 |           State: (none)
[task 2023-03-19T07:50:33.273Z] 07:50:33     INFO - PID 2256 | 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-19T07:50:33.274Z] 07:50:33     INFO - PID 2256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-19T07:50:33.274Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-19T07:50:33.275Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-19T07:50:33.275Z] 07:50:33     INFO - PID 2256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-19T07:50:33.275Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-19T07:50:33.276Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-19T07:50:33.276Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-19T07:50:33.277Z] 07:50:33     INFO - PID 2256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-19T07:50:33.277Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-19T07:50:33.279Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-19T07:50:33.279Z] 07:50:33     INFO - PID 2256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-19T07:50:33.280Z] 07:50:33     INFO - PID 2256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-19T07:50:33.280Z] 07:50:33     INFO - PID 2256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-19T07:50:33.281Z] 07:50:33     INFO - PID 2256 |           Blocker:  TelemetryController: shutting down
[task 2023-03-19T07:50:33.281Z] 07:50:33     INFO - PID 2256 |           Phase: profile-before-change-telemetry
[task 2023-03-19T07:50:33.282Z] 07:50:33     INFO - PID 2256 |           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-19T07:50:33.282Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-19T07:50:33.283Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-19T07:50:33.283Z] 07:50:33     INFO - PID 2256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-19T07:50:33.284Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-19T07:50:33.284Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-19T07:50:33.285Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-19T07:50:33.286Z] 07:50:33     INFO - PID 2256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-19T07:50:33.286Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-19T07:50:33.287Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-19T07:50:33.287Z] 07:50:33     INFO - PID 2256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-19T07:50:33.288Z] 07:50:33     INFO - PID 2256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-19T07:50:33.289Z] 07:50:33     INFO - PID 2256 | 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-19T07:50:33.289Z] 07:50:33     INFO - PID 2256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-19T07:50:33.290Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-19T07:50:33.290Z] 07:50:33     INFO - PID 2256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-19T07:50:33.291Z] 07:50:33     INFO - PID 2256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-19T07:50:33.291Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-19T07:50:33.291Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-19T07:50:33.292Z] 07:50:33     INFO - PID 2256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-19T07:50:33.293Z] 07:50:33     INFO - PID 2256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-19T07:50:33.293Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-19T07:50:33.294Z] 07:50:33     INFO - PID 2256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-19T07:50:33.294Z] 07:50:33     INFO - PID 2256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-19T07:50:33.295Z] 07:50:33     INFO - PID 2256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-19T07:50:35.559Z] 07:50:35     INFO - PID 2256 | 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-19T07:50:35.564Z] 07:50:35     INFO - PID 2256 | 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-19T07:50:35.565Z] 07:50:35     INFO - PID 2256 | 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-19T07:50:35.566Z] 07:50:35     INFO - PID 2256 | 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-19T07:50:35.566Z] 07:50:35     INFO - PID 2256 | 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-19T07:50:35.622Z] 07:50:35     INFO - Browser exited with return code 0
[task 2023-03-19T07:50:35.625Z] 07:50:35     INFO - Closing logging queue
[task 2023-03-19T07:50:35.626Z] 07:50:35     INFO - queue closed
[task 2023-03-19T07:50:37.866Z] 07:50:37     INFO - Application command: Z:\task_167921103207367\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167921103207367\AppData\Local\Temp\tmposgkq_2k
[task 2023-03-19T07:50:37.876Z] 07:50:37     INFO - PID 8632 | 1679212037653	Marionette	INFO	Marionette enabled
[task 2023-03-19T07:50:37.876Z] 07:50:37     INFO - PID 8632 | 1679212037657	Marionette	INFO	Listening on port 49543
[task 2023-03-19T07:50:37.877Z] 07:50:37     INFO - PID 8632 | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 58: Error: Can't find profile directory.
[task 2023-03-19T07:50:37.878Z] 07:50:37     INFO - PID 8632 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-19T07:50:37.879Z] 07:50:37     INFO - PID 8632 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167921103207367\\AppData\\Local\\Temp\\tmp9qqhwvig\\search.json.mozlz4", (void 0)))
[task 2023-03-19T07:50:37.879Z] 07:50:37     INFO - PID 8632 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-19T07:50:37.880Z] 07:50:37     INFO - PID 8632 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-19T07:50:37.881Z] 07:50:37     INFO - PID 8632 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-19T07:50:37.882Z] 07:50:37     INFO - PID 8632 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-19T07:50:37.883Z] 07:50:37     INFO - Starting runner
[task 2023-03-19T07:50:38.901Z] 07:50:38     INFO - TEST-START | /IndexedDB/idbobjectstore_add6.htm

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

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.