1810156 - Intermittent /fetch/api/credentials/authentication-redirection.any.serviceworker.html | single tracking bug

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

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

---

[task 2023-01-13T11:31:33.992Z] 11:31:33     INFO - TEST-START | /fetch/api/credentials/authentication-redirection.any.serviceworker.html
[task 2023-01-13T11:31:33.994Z] 11:31:33     INFO - Closing window 31ee07fd-e9c1-470a-977c-f9a8f554f468
[task 2023-01-13T11:31:34.020Z] 11:31:34     INFO - PID 7464 | console.error: (new TypeError("can't access property \"find\", this._searchProviderInfo is null", "resource:///modules/SearchSERPTelemetry.sys.mjs", 461))
[task 2023-01-13T11:31:34.075Z] 11:31:34     INFO - PID 7464 | console.error: (new TypeError("can't access property \"find\", this._searchProviderInfo is null", "resource:///modules/SearchSERPTelemetry.sys.mjs", 461))
[task 2023-01-13T11:31:44.103Z] 11:31:44     INFO - TEST-UNEXPECTED-TIMEOUT | /fetch/api/credentials/authentication-redirection.any.serviceworker.html | expected OK
[task 2023-01-13T11:31:44.103Z] 11:31:44     INFO - TEST-INFO took 10129ms
[task 2023-01-13T11:31:44.107Z] 11:31:44     INFO - PID 7464 | 1673609504105	Marionette	INFO	Stopped listening on port 63212
[task 2023-01-13T11:31:47.134Z] 11:31:47     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:47.138Z] 11:31:47     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:48.222Z] 11:31:48     INFO - PID 7464 | JavaScript error: resource://gre/modules/JSONFile.sys.mjs, line 184: Error: Data is not ready.
[task 2023-01-13T11:31:49.653Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.662Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:49.662Z] 11:31:49     INFO - PID 7464 | console.error: (new Error("IndexedDB: main/doh-config getLastModified() IndexedDB:  execute() The application is shutting down", "resource://services-settings/IDBHelpers.jsm", 18))
[task 2023-01-13T11:31:49.663Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.664Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:49.664Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.666Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:49.666Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.669Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.670Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:49.670Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:49.671Z] 11:31:49     INFO - PID 7464 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-01-13T11:31:49.682Z] 11:31:49     INFO - PID 7464 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-01-13T11:31:52.042Z] 11:31:52     INFO - PID 7464 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-13T11:31:52.043Z] 11:31:52     INFO - PID 7464 |           Blocker:  Waiting for ping task
[task 2023-01-13T11:31:52.043Z] 11:31:52     INFO - PID 7464 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-01-13T11:31:52.044Z] 11:31:52     INFO - PID 7464 |           State: (none)
[task 2023-01-13T11:31:52.045Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.045Z] 11:31:52     INFO - PID 7464 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-13T11:31:52.046Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-13T11:31:52.046Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-13T11:31:52.047Z] 11:31:52     INFO - PID 7464 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-13T11:31:52.047Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-13T11:31:52.048Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-13T11:31:52.049Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-13T11:31:52.049Z] 11:31:52     INFO - PID 7464 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-13T11:31:52.050Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-13T11:31:52.050Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-13T11:31:52.051Z] 11:31:52     INFO - PID 7464 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-13T11:31:52.052Z] 11:31:52     INFO - PID 7464 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T11:31:52.055Z] 11:31:52     INFO - PID 7464 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-13T11:31:52.055Z] 11:31:52     INFO - PID 7464 |           Blocker:  Waiting for ping task
[task 2023-01-13T11:31:52.057Z] 11:31:52     INFO - PID 7464 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-01-13T11:31:52.057Z] 11:31:52     INFO - PID 7464 |           State: (none)
[task 2023-01-13T11:31:52.058Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.058Z] 11:31:52     INFO - PID 7464 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-13T11:31:52.059Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-13T11:31:52.059Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-13T11:31:52.060Z] 11:31:52     INFO - PID 7464 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-13T11:31:52.060Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-13T11:31:52.061Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-13T11:31:52.062Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-13T11:31:52.062Z] 11:31:52     INFO - PID 7464 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-13T11:31:52.063Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-13T11:31:52.064Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-13T11:31:52.064Z] 11:31:52     INFO - PID 7464 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-13T11:31:52.065Z] 11:31:52     INFO - PID 7464 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T11:31:52.065Z] 11:31:52     INFO - PID 7464 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-13T11:31:52.066Z] 11:31:52     INFO - PID 7464 |           Blocker:  TelemetryController: shutting down
[task 2023-01-13T11:31:52.067Z] 11:31:52     INFO - PID 7464 |           Phase: profile-before-change-telemetry
[task 2023-01-13T11:31:52.067Z] 11:31:52     INFO - PID 7464 |           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-01-13T11:31:52.068Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-13T11:31:52.069Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-13T11:31:52.069Z] 11:31:52     INFO - PID 7464 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-13T11:31:52.070Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-13T11:31:52.071Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-13T11:31:52.071Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-13T11:31:52.071Z] 11:31:52     INFO - PID 7464 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-13T11:31:52.072Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-13T11:31:52.072Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-13T11:31:52.073Z] 11:31:52     INFO - PID 7464 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-13T11:31:52.074Z] 11:31:52     INFO - PID 7464 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T11:31:52.075Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.075Z] 11:31:52     INFO - PID 7464 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-13T11:31:52.075Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-13T11:31:52.075Z] 11:31:52     INFO - PID 7464 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-13T11:31:52.076Z] 11:31:52     INFO - PID 7464 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-13T11:31:52.077Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-13T11:31:52.078Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-13T11:31:52.078Z] 11:31:52     INFO - PID 7464 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-13T11:31:52.079Z] 11:31:52     INFO - PID 7464 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-13T11:31:52.079Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-13T11:31:52.080Z] 11:31:52     INFO - PID 7464 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-13T11:31:52.080Z] 11:31:52     INFO - PID 7464 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-13T11:31:52.081Z] 11:31:52     INFO - PID 7464 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-13T11:31:52.434Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.438Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.439Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.440Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.441Z] 11:31:52     INFO - PID 7464 | 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-01-13T11:31:52.499Z] 11:31:52     INFO - Browser exited with return code 0
[task 2023-01-13T11:31:52.503Z] 11:31:52     INFO - Closing logging queue
[task 2023-01-13T11:31:52.503Z] 11:31:52     INFO - queue closed
[task 2023-01-13T11:31:52.530Z] 11:31:52     INFO - Application command: Z:\task_167360308511179\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167360308511179\AppData\Local\Temp\tmpdutm43bq
[task 2023-01-13T11:31:52.543Z] 11:31:52     INFO - PID 7276 | 1673609478362	Marionette	INFO	Marionette enabled
[task 2023-01-13T11:31:52.546Z] 11:31:52     INFO - PID 7276 | 1673609478365	Marionette	INFO	Listening on port 63237
[task 2023-01-13T11:31:52.547Z] 11:31:52     INFO - PID 7276 | JavaScript error: resource://gre/modules/XULStore.jsm, line 58: Error: Can't find profile directory.
[task 2023-01-13T11:31:52.548Z] 11:31:52     INFO - PID 7276 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167360308511179\\AppData\\Local\\Temp\\tmptulsn_xt\\search.json.mozlz4", (void 0)))
[task 2023-01-13T11:31:52.548Z] 11:31:52     INFO - PID 7276 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T11:31:52.550Z] 11:31:52     INFO - PID 7276 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T11:31:52.550Z] 11:31:52     INFO - PID 7276 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T11:31:52.551Z] 11:31:52     INFO - PID 7276 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-13T11:31:52.551Z] 11:31:52     INFO - Starting runner
[task 2023-01-13T11:31:53.434Z] 11:31:53     INFO - TEST-START | /fetch/api/credentials/authentication-redirection.any.html

Comment 1

[Intermittent Failures Robot]

1 failures in 3530 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-01-09&endday=2023-01-15&tree=all

Comment 2

[Intermittent Failures Robot]

3 failures in 3606 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-beta: 1
• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-01-30&endday=2023-02-05&tree=all

Comment 3

[Intermittent Failures Robot]

4 failures in 3856 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1
• autoland: 2
• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 2
  • opt: 2
• windows10-64-2004-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-02-13&endday=2023-02-19&tree=all

Comment 4

[Sunil Mayya]

We don't see any necko specific problems from the logs.
Additionally, the failure is seen only for tests related to service workers.
Hence, moving it to the service workers component.

Comment 5

[Intermittent Failures Robot]

2 failures in 3752 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1
• try: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1
• windows10-64-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-02-27&endday=2023-03-05&tree=all

Comment 6

[Intermittent Failures Robot]

1 failures in 3761 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-03-13&endday=2023-03-19&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 3863 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• windows11-64-2009-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-03-27&endday=2023-04-02&tree=all

Comment 8

[Intermittent Failures Robot]

1 failures in 4077 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810156&startday=2023-05-08&endday=2023-05-14&tree=all

Comment 9

[BugBot [:suhaib / :marco/ :calixte]]

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