Closed
Bug 1825551
Opened 2 years ago
Closed 11 months ago
Intermittent /service-workers/service-worker/update-after-oneday.https.html | single tracking bug
Categories
(Core :: DOM: Service Workers, defect, P5)
Core
DOM: Service Workers
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=410801408&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/IHuJYSl_TU2GBwPtXzBK-A/runs/0/artifacts/public/logs/live_backing.log
[task 2023-03-30T13:36:20.743Z] 13:36:20 INFO - TEST-OK | /service-workers/service-worker/update-after-navigation-redirect.https.html | took 12883ms
[task 2023-03-30T13:36:20.748Z] 13:36:20 INFO - TEST-START | /service-workers/service-worker/update-after-oneday.https.html
[task 2023-03-30T13:36:20.748Z] 13:36:20 INFO - Setting pref dom.serviceWorkers.mitigations.bypass_on_fault to true
[task 2023-03-30T13:36:20.755Z] 13:36:20 INFO - Setting pref dom.serviceWorkers.enabled to true
[task 2023-03-30T13:36:20.767Z] 13:36:20 INFO - Setting pref dom.serviceWorkers.mitigations.bypass_on_fault to false
[task 2023-03-30T13:36:20.775Z] 13:36:20 INFO - Setting pref dom.serviceWorkers.enabled to true
[task 2023-03-30T13:36:20.783Z] 13:36:20 INFO - Setting pref dom.serviceWorkers.testUpdateOverOneDay to true
[task 2023-03-30T13:36:20.790Z] 13:36:20 INFO - Closing window acbfce73-1177-4e57-a93c-156bc635f57d
[task 2023-03-30T13:36:30.896Z] 13:36:30 INFO -
[task 2023-03-30T13:36:30.896Z] 13:36:30 INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/update-after-oneday.https.html | Update should be triggered after a functional event when last update time is over 24 hours - Test timed out
[task 2023-03-30T13:36:30.902Z] 13:36:30 INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/update-after-oneday.https.html | expected OK
[task 2023-03-30T13:36:30.902Z] 13:36:30 INFO - TEST-INFO took 10159ms
[task 2023-03-30T13:36:30.906Z] 13:36:30 INFO - PID 7576 | 1680183390906 Marionette INFO Stopped listening on port 55095
[task 2023-03-30T13:36:30.918Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.922Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.923Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.925Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.926Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.927Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:30.929Z] 13:36:30 INFO - PID 7576 | [Child 952, 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-30T13:36:48.001Z] 13:36:48 INFO - PID 7576 | 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-30T13:36:52.552Z] 13:36:52 INFO - PID 7576 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-30T13:36:52.552Z] 13:36:52 INFO - PID 7576 | Blocker: Waiting for ping task
[task 2023-03-30T13:36:52.565Z] 13:36:52 INFO - PID 7576 | Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-30T13:36:52.565Z] 13:36:52 INFO - PID 7576 | State: (none)
[task 2023-03-30T13:36:52.566Z] 13:36:52 INFO - PID 7576 | 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-30T13:36:52.567Z] 13:36:52 INFO - PID 7576 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-30T13:36:52.568Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-30T13:36:52.568Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-30T13:36:52.569Z] 13:36:52 INFO - PID 7576 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-30T13:36:52.569Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-30T13:36:52.570Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-30T13:36:52.570Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-30T13:36:52.571Z] 13:36:52 INFO - PID 7576 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-30T13:36:52.571Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-30T13:36:52.572Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-30T13:36:52.572Z] 13:36:52 INFO - PID 7576 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-30T13:36:52.573Z] 13:36:52 INFO - PID 7576 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-30T13:36:52.573Z] 13:36:52 INFO - PID 7576 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-30T13:36:52.578Z] 13:36:52 INFO - PID 7576 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-30T13:36:52.579Z] 13:36:52 INFO - PID 7576 | Blocker: Waiting for ping task
[task 2023-03-30T13:36:52.579Z] 13:36:52 INFO - PID 7576 | Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-30T13:36:52.580Z] 13:36:52 INFO - PID 7576 | State: (none)
[task 2023-03-30T13:36:52.580Z] 13:36:52 INFO - PID 7576 | 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-30T13:36:52.581Z] 13:36:52 INFO - PID 7576 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-30T13:36:52.582Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-30T13:36:52.582Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-30T13:36:52.583Z] 13:36:52 INFO - PID 7576 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-30T13:36:52.584Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-30T13:36:52.584Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-30T13:36:52.585Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-30T13:36:52.585Z] 13:36:52 INFO - PID 7576 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-30T13:36:52.586Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-30T13:36:52.586Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-30T13:36:52.587Z] 13:36:52 INFO - PID 7576 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-30T13:36:52.587Z] 13:36:52 INFO - PID 7576 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-30T13:36:52.588Z] 13:36:52 INFO - PID 7576 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-30T13:36:52.588Z] 13:36:52 INFO - PID 7576 | Blocker: TelemetryController: shutting down
[task 2023-03-30T13:36:52.589Z] 13:36:52 INFO - PID 7576 | Phase: profile-before-change-telemetry
[task 2023-03-30T13:36:52.589Z] 13:36:52 INFO - PID 7576 | 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-30T13:36:52.590Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-30T13:36:52.590Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-30T13:36:52.591Z] 13:36:52 INFO - PID 7576 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-30T13:36:52.591Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-30T13:36:52.592Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-30T13:36:52.593Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-30T13:36:52.593Z] 13:36:52 INFO - PID 7576 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-30T13:36:52.594Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-30T13:36:52.594Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-30T13:36:52.595Z] 13:36:52 INFO - PID 7576 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-30T13:36:52.595Z] 13:36:52 INFO - PID 7576 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-30T13:36:52.596Z] 13:36:52 INFO - PID 7576 | 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-30T13:36:52.596Z] 13:36:52 INFO - PID 7576 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-30T13:36:52.597Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-30T13:36:52.597Z] 13:36:52 INFO - PID 7576 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-30T13:36:52.598Z] 13:36:52 INFO - PID 7576 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-30T13:36:52.598Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-30T13:36:52.599Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-30T13:36:52.599Z] 13:36:52 INFO - PID 7576 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-30T13:36:52.600Z] 13:36:52 INFO - PID 7576 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-30T13:36:52.600Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-30T13:36:52.601Z] 13:36:52 INFO - PID 7576 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-30T13:36:52.601Z] 13:36:52 INFO - PID 7576 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-30T13:36:52.602Z] 13:36:52 INFO - PID 7576 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-30T13:36:53.006Z] 13:36:53 INFO - PID 7576 | 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-30T13:36:53.021Z] 13:36:53 INFO - PID 7576 | 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-30T13:36:53.022Z] 13:36:53 INFO - PID 7576 | 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-30T13:36:53.023Z] 13:36:53 INFO - PID 7576 | 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-30T13:36:53.024Z] 13:36:53 INFO - PID 7576 | 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-30T13:36:53.085Z] 13:36:53 INFO - Browser exited with return code 0
[task 2023-03-30T13:36:53.088Z] 13:36:53 INFO - Closing logging queue
[task 2023-03-30T13:36:53.088Z] 13:36:53 INFO - queue closed
[task 2023-03-30T13:36:56.538Z] 13:36:56 INFO - Application command: Z:\task_168017693101125\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_168017693101125\AppData\Local\Temp\tmp3feqpo5y
[task 2023-03-30T13:36:56.554Z] 13:36:56 INFO - PID 3732 | 1680183192154 Marionette INFO Marionette enabled
[task 2023-03-30T13:36:56.556Z] 13:36:56 INFO - PID 3732 | 1680183192157 Marionette INFO Listening on port 55220
[task 2023-03-30T13:36:56.556Z] 13:36:56 INFO - PID 3732 | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 58: Error: Can't find profile directory.
[task 2023-03-30T13:36:56.557Z] 13:36:56 INFO - PID 3732 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_168017693101125\\AppData\\Local\\Temp\\tmpj63vu79q\\search.json.mozlz4", (void 0)))
[task 2023-03-30T13:36:56.558Z] 13:36:56 INFO - PID 3732 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-30T13:36:56.559Z] 13:36:56 INFO - PID 3732 | [Child 7544, 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-30T13:36:56.560Z] 13:36:56 INFO - PID 3732 | [Child 7544, 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-30T13:36:56.560Z] 13:36:56 INFO - PID 3732 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-30T13:36:56.561Z] 13:36:56 INFO - PID 3732 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-30T13:36:56.562Z] 13:36:56 INFO - PID 3732 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-30T13:36:56.563Z] 13:36:56 INFO - PID 3732 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-30T13:36:56.564Z] 13:36:56 INFO - PID 3732 | 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-30T13:36:56.564Z] 13:36:56 INFO - Starting runner
[task 2023-03-30T13:36:57.574Z] 13:36:57 INFO - TEST-START | /service-workers/service-worker/update-bytecheck-cors-import.https.html
Comment hidden (Intermittent Failures Robot) |
Comment 2•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Reporter | ||
Comment 3•1 year ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=448133899&repo=mozilla-esr115
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Comment hidden (Intermittent Failures Robot) |
Comment 5•11 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: REOPENED → RESOLVED
Closed: 2 years ago → 11 months ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•