Closed Bug 1822852 Opened 2 years ago Closed 2 years ago

Intermittent /streams/writable-streams/start.any.serviceworker.html | single tracking bug

Categories

(Core :: DOM: Streams, defect, P5)

Product:
Core
Component:
DOM: Streams
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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

[task 2023-03-16T15:27:13.814Z] 15:27:13     INFO - TEST-START | /streams/writable-streams/write.any.serviceworker.html
[task 2023-03-16T15:27:13.815Z] 15:27:13     INFO - Closing window dd5002df-22f8-4e08-805d-58e52cdfdd0c
[task 2023-03-16T15:27:24.016Z] 15:27:24     INFO - TEST-UNEXPECTED-TIMEOUT | /streams/writable-streams/write.any.serviceworker.html | expected OK
[task 2023-03-16T15:27:24.016Z] 15:27:24     INFO - TEST-INFO took 10210ms
[task 2023-03-16T15:27:24.021Z] 15:27:24     INFO - PID 1480 | 1678980444021	Marionette	INFO	Stopped listening on port 51116
[task 2023-03-16T15:27:39.096Z] 15:27:39     INFO - PID 1480 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.sys.mjs", 370))
[task 2023-03-16T15:27:45.638Z] 15:27:45     INFO - PID 1480 | 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-16T15:27:48.763Z] 15:27:48     INFO - PID 1480 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-16T15:27:48.767Z] 15:27:48     INFO - PID 1480 |           Blocker:  Waiting for ping task
[task 2023-03-16T15:27:48.768Z] 15:27:48     INFO - PID 1480 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-16T15:27:48.768Z] 15:27:48     INFO - PID 1480 |           State: (none)
[task 2023-03-16T15:27:48.769Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.770Z] 15:27:48     INFO - PID 1480 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-16T15:27:48.770Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-16T15:27:48.771Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-16T15:27:48.772Z] 15:27:48     INFO - PID 1480 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-16T15:27:48.772Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-16T15:27:48.774Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-16T15:27:48.774Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-16T15:27:48.775Z] 15:27:48     INFO - PID 1480 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-16T15:27:48.775Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-16T15:27:48.776Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-16T15:27:48.777Z] 15:27:48     INFO - PID 1480 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-16T15:27:48.777Z] 15:27:48     INFO - PID 1480 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-16T15:27:48.778Z] 15:27:48     INFO - PID 1480 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-16T15:27:48.779Z] 15:27:48     INFO - PID 1480 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-16T15:27:48.779Z] 15:27:48     INFO - PID 1480 |           Blocker:  Waiting for ping task
[task 2023-03-16T15:27:48.781Z] 15:27:48     INFO - PID 1480 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-16T15:27:48.781Z] 15:27:48     INFO - PID 1480 |           State: (none)
[task 2023-03-16T15:27:48.782Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.783Z] 15:27:48     INFO - PID 1480 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-16T15:27:48.783Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-16T15:27:48.784Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-16T15:27:48.784Z] 15:27:48     INFO - PID 1480 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-16T15:27:48.785Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-16T15:27:48.785Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-16T15:27:48.786Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-16T15:27:48.786Z] 15:27:48     INFO - PID 1480 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-16T15:27:48.787Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-16T15:27:48.787Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-16T15:27:48.788Z] 15:27:48     INFO - PID 1480 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-16T15:27:48.789Z] 15:27:48     INFO - PID 1480 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-16T15:27:48.789Z] 15:27:48     INFO - PID 1480 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-16T15:27:48.790Z] 15:27:48     INFO - PID 1480 |           Blocker:  TelemetryController: shutting down
[task 2023-03-16T15:27:48.790Z] 15:27:48     INFO - PID 1480 |           Phase: profile-before-change-telemetry
[task 2023-03-16T15:27:48.791Z] 15:27:48     INFO - PID 1480 |           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-16T15:27:48.792Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-16T15:27:48.792Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-16T15:27:48.793Z] 15:27:48     INFO - PID 1480 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-16T15:27:48.793Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-16T15:27:48.794Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-16T15:27:48.795Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-16T15:27:48.796Z] 15:27:48     INFO - PID 1480 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-16T15:27:48.796Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-16T15:27:48.797Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-16T15:27:48.798Z] 15:27:48     INFO - PID 1480 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-16T15:27:48.798Z] 15:27:48     INFO - PID 1480 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-16T15:27:48.799Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.799Z] 15:27:48     INFO - PID 1480 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-16T15:27:48.800Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-16T15:27:48.801Z] 15:27:48     INFO - PID 1480 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-16T15:27:48.801Z] 15:27:48     INFO - PID 1480 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-16T15:27:48.802Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-16T15:27:48.803Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-16T15:27:48.804Z] 15:27:48     INFO - PID 1480 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-16T15:27:48.804Z] 15:27:48     INFO - PID 1480 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-16T15:27:48.804Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-16T15:27:48.806Z] 15:27:48     INFO - PID 1480 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-16T15:27:48.806Z] 15:27:48     INFO - PID 1480 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-16T15:27:48.807Z] 15:27:48     INFO - PID 1480 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-16T15:27:48.807Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.809Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.810Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.810Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.812Z] 15:27:48     INFO - PID 1480 | 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-16T15:27:48.872Z] 15:27:48     INFO - Browser exited with return code 0
[task 2023-03-16T15:27:48.875Z] 15:27:48     INFO - Closing logging queue
[task 2023-03-16T15:27:48.877Z] 15:27:48     INFO - queue closed
[task 2023-03-16T15:27:48.919Z] 15:27:48     INFO - Application command: Z:\task_167897871827570\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167897871827570\AppData\Local\Temp\tmpfaxkaojy
[task 2023-03-16T15:27:48.931Z] 15:27:48     INFO - PID 7660 | 1678980432360	Marionette	INFO	Marionette enabled
[task 2023-03-16T15:27:48.932Z] 15:27:48     INFO - PID 7660 | 1678980432364	Marionette	INFO	Listening on port 51226
[task 2023-03-16T15:27:48.933Z] 15:27:48     INFO - PID 7660 | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 58: Error: Can't find profile directory.
[task 2023-03-16T15:27:48.934Z] 15:27:48     INFO - PID 7660 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167897871827570\\AppData\\Local\\Temp\\tmpgknrx29y\\search.json.mozlz4", (void 0)))
[task 2023-03-16T15:27:48.935Z] 15:27:48     INFO - PID 7660 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-16T15:27:48.936Z] 15:27:48     INFO - PID 7660 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-16T15:27:48.936Z] 15:27:48     INFO - Starting runner
[task 2023-03-16T15:27:49.422Z] 15:27:49     INFO - PID 7660 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-16T15:27:49.432Z] 15:27:49     INFO - PID 7660 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-16T15:27:49.433Z] 15:27:49     INFO - PID 7660 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))

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

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE

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

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

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