Closed Bug 1824108 Opened 3 years ago Closed 2 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /IndexedDB/structured-clone.any.worker.html?81-100 | SyntaxError: SyntaxError - Test timed out

Categories

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

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2023-03-23T11:08:02.442Z] 11:08:02     INFO - TEST-PASS | /IndexedDB/structured-clone.any.worker.html?81-100 | ReferenceError: ReferenceError: ghi 
[task 2023-03-23T11:08:02.443Z] 11:08:02     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/structured-clone.any.worker.html?81-100 | SyntaxError: SyntaxError - Test timed out
[task 2023-03-23T11:08:02.443Z] 11:08:02     INFO - 
[task 2023-03-23T11:08:02.443Z] 11:08:02     INFO - TEST-UNEXPECTED-NOTRUN | /IndexedDB/structured-clone.any.worker.html?81-100 | SyntaxError: SyntaxError: ghi - expected PASS
[task 2023-03-23T11:08:02.444Z] 11:08:02     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/structured-clone.any.worker.html?81-100 | expected OK
[task 2023-03-23T11:08:02.444Z] 11:08:02     INFO - TEST-INFO took 60102ms
[task 2023-03-23T11:08:02.446Z] 11:08:02     INFO - PID 4504 | 1679569682438	Marionette	INFO	Stopped listening on port 55458
[task 2023-03-23T11:08:10.160Z] 11:08:10     INFO - PID 4504 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-23T11:08:10.163Z] 11:08:10     INFO - PID 4504 |           Blocker:  Waiting for ping task
[task 2023-03-23T11:08:10.164Z] 11:08:10     INFO - PID 4504 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-23T11:08:10.164Z] 11:08:10     INFO - PID 4504 |           State: (none)
[task 2023-03-23T11:08:10.165Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.166Z] 11:08:10     INFO - PID 4504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-23T11:08:10.167Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-23T11:08:10.167Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-23T11:08:10.168Z] 11:08:10     INFO - PID 4504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-23T11:08:10.168Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-23T11:08:10.169Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-23T11:08:10.169Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-23T11:08:10.170Z] 11:08:10     INFO - PID 4504 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-23T11:08:10.171Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-23T11:08:10.171Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-23T11:08:10.172Z] 11:08:10     INFO - PID 4504 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-23T11:08:10.173Z] 11:08:10     INFO - PID 4504 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-23T11:08:10.173Z] 11:08:10     INFO - PID 4504 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-23T11:08:10.208Z] 11:08:10     INFO - PID 4504 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-23T11:08:10.215Z] 11:08:10     INFO - PID 4504 |           Blocker:  Waiting for ping task
[task 2023-03-23T11:08:10.215Z] 11:08:10     INFO - PID 4504 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-23T11:08:10.216Z] 11:08:10     INFO - PID 4504 |           State: (none)
[task 2023-03-23T11:08:10.216Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.217Z] 11:08:10     INFO - PID 4504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-23T11:08:10.218Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-23T11:08:10.219Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-23T11:08:10.219Z] 11:08:10     INFO - PID 4504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-23T11:08:10.220Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-23T11:08:10.220Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-23T11:08:10.221Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-23T11:08:10.222Z] 11:08:10     INFO - PID 4504 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-23T11:08:10.222Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-23T11:08:10.223Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-23T11:08:10.223Z] 11:08:10     INFO - PID 4504 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-23T11:08:10.223Z] 11:08:10     INFO - PID 4504 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-23T11:08:10.224Z] 11:08:10     INFO - PID 4504 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-23T11:08:10.225Z] 11:08:10     INFO - PID 4504 |           Blocker:  TelemetryController: shutting down
[task 2023-03-23T11:08:10.225Z] 11:08:10     INFO - PID 4504 |           Phase: profile-before-change-telemetry
[task 2023-03-23T11:08:10.226Z] 11:08:10     INFO - PID 4504 |           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-23T11:08:10.227Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-23T11:08:10.227Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-23T11:08:10.228Z] 11:08:10     INFO - PID 4504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-23T11:08:10.228Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-23T11:08:10.229Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-23T11:08:10.229Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-23T11:08:10.230Z] 11:08:10     INFO - PID 4504 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-23T11:08:10.230Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-23T11:08:10.231Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-23T11:08:10.232Z] 11:08:10     INFO - PID 4504 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-23T11:08:10.232Z] 11:08:10     INFO - PID 4504 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-23T11:08:10.233Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.233Z] 11:08:10     INFO - PID 4504 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-23T11:08:10.234Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-23T11:08:10.234Z] 11:08:10     INFO - PID 4504 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-23T11:08:10.235Z] 11:08:10     INFO - PID 4504 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-23T11:08:10.235Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-23T11:08:10.236Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-23T11:08:10.236Z] 11:08:10     INFO - PID 4504 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-23T11:08:10.237Z] 11:08:10     INFO - PID 4504 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-23T11:08:10.237Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-23T11:08:10.238Z] 11:08:10     INFO - PID 4504 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-23T11:08:10.239Z] 11:08:10     INFO - PID 4504 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-23T11:08:10.239Z] 11:08:10     INFO - PID 4504 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-23T11:08:10.663Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.678Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.687Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.688Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.689Z] 11:08:10     INFO - PID 4504 | 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-23T11:08:10.757Z] 11:08:10     INFO - Browser exited with return code 0
[task 2023-03-23T11:08:10.761Z] 11:08:10     INFO - Closing logging queue
[task 2023-03-23T11:08:10.761Z] 11:08:10     INFO - queue closed
[task 2023-03-23T11:08:12.389Z] 11:08:12     INFO - Application command: Z:\task_167956646024164\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167956646024164\AppData\Local\Temp\tmpha325ifo
[task 2023-03-23T11:08:12.398Z] 11:08:12     INFO - PID 4352 | 1679568919998	Marionette	INFO	Marionette enabled
[task 2023-03-23T11:08:12.399Z] 11:08:12     INFO - PID 4352 | 1679568920001	Marionette	INFO	Listening on port 55459
[task 2023-03-23T11:08:12.400Z] 11:08:12     INFO - PID 4352 | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 58: Error: Can't find profile directory.
[task 2023-03-23T11:08:12.401Z] 11:08:12     INFO - PID 4352 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167956646024164\\AppData\\Local\\Temp\\tmp_kh_24ho\\search.json.mozlz4", (void 0)))
[task 2023-03-23T11:08:12.402Z] 11:08:12     INFO - PID 4352 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-23T11:08:12.403Z] 11:08:12     INFO - PID 4352 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-23T11:08:12.403Z] 11:08:12     INFO - PID 4352 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-23T11:08:12.404Z] 11:08:12     INFO - PID 4352 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-23T11:08:12.405Z] 11:08:12     INFO - PID 4352 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-23T11:08:12.405Z] 11:08:12     INFO - PID 4352 | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 324))
[task 2023-03-23T11:08:12.406Z] 11:08:12     INFO - Starting runner
[task 2023-03-23T11:08:13.425Z] 11:08:13     INFO - TEST-START | /IndexedDB/structured-clone.any.worker.html?61-80
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.