Closed Bug 1825165 Opened 3 years ago Closed 3 years ago

Intermittent mozilla/tests/service-workers/no_intercept_for_crossorigin_media.https.html | single tracking bug

Categories

(Core :: DOM: Service Workers, defect, P5)

Product:
Core
Component:
DOM: Service Workers
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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

[task 2023-03-28T16:54:21.750Z] 16:54:21     INFO - TEST-START | /_mozilla/service-workers/no_intercept_for_crossorigin_media.https.html
[task 2023-03-28T16:54:21.754Z] 16:54:21     INFO - Closing window 2a1ebaf5-d2d8-4025-977e-93eaedc948a9
[task 2023-03-28T16:54:32.003Z] 16:54:32     INFO - 
[task 2023-03-28T16:54:32.003Z] 16:54:32     INFO - TEST-UNEXPECTED-TIMEOUT | /_mozilla/service-workers/no_intercept_for_crossorigin_media.https.html | Service worker does not intercept a cross-origin media range request - Test timed out
[task 2023-03-28T16:54:32.004Z] 16:54:32     INFO - 
[task 2023-03-28T16:54:32.004Z] 16:54:32     INFO - TEST-UNEXPECTED-NOTRUN | /_mozilla/service-workers/no_intercept_for_crossorigin_media.https.html | Service worker intercepts a cross-origin non-range media request - expected PASS
[task 2023-03-28T16:54:32.004Z] 16:54:32     INFO - TEST-UNEXPECTED-TIMEOUT | /_mozilla/service-workers/no_intercept_for_crossorigin_media.https.html | expected OK
[task 2023-03-28T16:54:32.004Z] 16:54:32     INFO - TEST-INFO took 10254ms
[task 2023-03-28T16:54:32.006Z] 16:54:32     INFO - PID 3256 | 1680022472004	Marionette	INFO	Stopped listening on port 56993
[task 2023-03-28T16:54:32.016Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.017Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.018Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.019Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.020Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.020Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.022Z] 16:54:32     INFO - PID 3256 | [Child 3266, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.486Z] 16:54:32     INFO - PID 3256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-28T16:54:32.487Z] 16:54:32     INFO - PID 3256 |           Blocker:  Waiting for ping task
[task 2023-03-28T16:54:32.487Z] 16:54:32     INFO - PID 3256 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-28T16:54:32.487Z] 16:54:32     INFO - PID 3256 |           State: (none)
[task 2023-03-28T16:54:32.488Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.489Z] 16:54:32     INFO - PID 3256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-28T16:54:32.489Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-28T16:54:32.489Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-28T16:54:32.490Z] 16:54:32     INFO - PID 3256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-28T16:54:32.490Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-28T16:54:32.491Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-28T16:54:32.491Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-28T16:54:32.491Z] 16:54:32     INFO - PID 3256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-28T16:54:32.492Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-28T16:54:32.492Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-28T16:54:32.493Z] 16:54:32     INFO - PID 3256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-28T16:54:32.493Z] 16:54:32     INFO - PID 3256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-28T16:54:32.494Z] 16:54:32     INFO - PID 3256 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-28T16:54:32.494Z] 16:54:32     INFO - PID 3256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-28T16:54:32.495Z] 16:54:32     INFO - PID 3256 |           Blocker:  Waiting for ping task
[task 2023-03-28T16:54:32.495Z] 16:54:32     INFO - PID 3256 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-28T16:54:32.496Z] 16:54:32     INFO - PID 3256 |           State: (none)
[task 2023-03-28T16:54:32.496Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.497Z] 16:54:32     INFO - PID 3256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-28T16:54:32.497Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-28T16:54:32.498Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-28T16:54:32.498Z] 16:54:32     INFO - PID 3256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-28T16:54:32.499Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-28T16:54:32.499Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-28T16:54:32.499Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-28T16:54:32.500Z] 16:54:32     INFO - PID 3256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-28T16:54:32.500Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-28T16:54:32.501Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-28T16:54:32.501Z] 16:54:32     INFO - PID 3256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-28T16:54:32.502Z] 16:54:32     INFO - PID 3256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-28T16:54:32.502Z] 16:54:32     INFO - PID 3256 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-28T16:54:32.503Z] 16:54:32     INFO - PID 3256 |           Blocker:  TelemetryController: shutting down
[task 2023-03-28T16:54:32.503Z] 16:54:32     INFO - PID 3256 |           Phase: profile-before-change-telemetry
[task 2023-03-28T16:54:32.504Z] 16:54:32     INFO - PID 3256 |           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-28T16:54:32.504Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-28T16:54:32.504Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-28T16:54:32.505Z] 16:54:32     INFO - PID 3256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-28T16:54:32.505Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-28T16:54:32.506Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-28T16:54:32.506Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-28T16:54:32.506Z] 16:54:32     INFO - PID 3256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-28T16:54:32.507Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-28T16:54:32.507Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-28T16:54:32.508Z] 16:54:32     INFO - PID 3256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-28T16:54:32.508Z] 16:54:32     INFO - PID 3256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-28T16:54:32.509Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.509Z] 16:54:32     INFO - PID 3256 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-28T16:54:32.509Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-28T16:54:32.510Z] 16:54:32     INFO - PID 3256 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-28T16:54:32.510Z] 16:54:32     INFO - PID 3256 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-28T16:54:32.511Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-28T16:54:32.511Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-28T16:54:32.511Z] 16:54:32     INFO - PID 3256 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-28T16:54:32.512Z] 16:54:32     INFO - PID 3256 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-28T16:54:32.512Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-28T16:54:32.512Z] 16:54:32     INFO - PID 3256 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-28T16:54:32.513Z] 16:54:32     INFO - PID 3256 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-28T16:54:32.513Z] 16:54:32     INFO - PID 3256 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-28T16:54:32.525Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.526Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.526Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.527Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.528Z] 16:54:32     INFO - PID 3256 | 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-28T16:54:32.741Z] 16:54:32     INFO - Browser exited with return code 0
[task 2023-03-28T16:54:32.744Z] 16:54:32     INFO - Closing logging queue
[task 2023-03-28T16:54:32.744Z] 16:54:32     INFO - queue closed
[task 2023-03-28T16:54:32.822Z] 16:54:32     INFO - Application command: /opt/worker/tasks/task_168002085018266/build/application/Firefox Developer Edition.app/Contents/MacOS/firefox --marionette about:blank -foreground -profile /var/folders/41/0wfbzkvj4dlf_qqdn_pr3g_h000014/T/tmpg3pa8tub
[task 2023-03-28T16:54:32.830Z] 16:54:32     INFO - PID 3279 | 1680022460564	Marionette	INFO	Marionette enabled
[task 2023-03-28T16:54:32.831Z] 16:54:32     INFO - PID 3279 | 1680022460759	Marionette	INFO	Listening on port 57049
[task 2023-03-28T16:54:32.831Z] 16:54:32     INFO - PID 3279 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /var/folders/41/0wfbzkvj4dlf_qqdn_pr3g_h000014/T/tmpurcxpx3a/search.json.mozlz4", (void 0)))
[task 2023-03-28T16:54:32.832Z] 16:54:32     INFO - PID 3279 | [Child 3285, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.832Z] 16:54:32     INFO - PID 3279 | [Child 3285, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-03-28T16:54:32.833Z] 16:54:32     INFO - PID 3279 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-28T16:54:32.833Z] 16:54:32     INFO - PID 3279 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-28T16:54:32.834Z] 16:54:32     INFO - PID 3279 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-28T16:54:32.835Z] 16:54:32     INFO - PID 3279 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-28T16:54:32.835Z] 16:54:32     INFO - Starting runner
[task 2023-03-28T16:54:33.202Z] 16:54:33     INFO - PID 3279 | 2023-03-28 16:54:33.201 firefox[3279:85608] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.firefoxdeveloperedition.savedState/window_1.data: No such file or directory (2)
[task 2023-03-28T16:54:33.460Z] 16:54:33     INFO - Installing extension from /opt/worker/tasks/task_168002085018266/build/tests/extensions/specialpowers@mozilla.org.xpi
[task 2023-03-28T16:54:33.671Z] 16:54:33     INFO - TEST-START | /_mozilla/service-workers/update_completes_in_disconnected_global.https.html
Component: General → DOM: Service Workers
Product: Testing → Core

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

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

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=420072287&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: 3 years ago → 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.