Closed Bug 1816117 Opened 2 years ago Closed 6 months ago

Intermittent /storage/buckets/buckets_storage_policy.tentative.https.any.serviceworker.html | single tracking bug

Categories

(Core :: Storage: Quota Manager, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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


[task 2023-02-10T12:54:36.791Z] 12:54:36     INFO - TEST-START | /storage/buckets/buckets_storage_policy.tentative.https.any.serviceworker.html
[task 2023-02-10T12:54:36.798Z] 12:54:36     INFO - Clearing origin https://web-platform.test:8443/storage/buckets/buckets_storage_policy.tentative.https.any.serviceworker.html
[task 2023-02-10T12:54:36.803Z] 12:54:36     INFO - Closing window d7d4962a-b783-40ad-93e5-08244b21f32a
[task 2023-02-10T12:54:36.861Z] 12:54:36     INFO - PID 6304 | console.error: (new TypeError("can't access property \"find\", this._searchProviderInfo is null", "resource:///modules/SearchSERPTelemetry.sys.mjs", 468))
[task 2023-02-10T12:54:46.894Z] 12:54:46     INFO - TEST-UNEXPECTED-TIMEOUT | /storage/buckets/buckets_storage_policy.tentative.https.any.serviceworker.html | expected ERROR
[task 2023-02-10T12:54:46.894Z] 12:54:46     INFO - TEST-INFO expected ERROR | took 10103ms
[task 2023-02-10T12:54:46.899Z] 12:54:46     INFO - Restarting browser for new test group
[task 2023-02-10T12:54:46.901Z] 12:54:46     INFO - PID 6304 | 1676033686901	Marionette	INFO	Stopped listening on port 59009
[task 2023-02-10T12:54:47.840Z] 12:54:47     INFO - PID 6304 | JavaScript error: resource:///modules/QuickSuggest.sys.mjs, line 385: TypeError: can't access property "gBrowser", win is null
[task 2023-02-10T12:54:47.847Z] 12:54:47     INFO - PID 6304 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:47.848Z] 12:54:47     INFO - PID 6304 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:47.848Z] 12:54:47     INFO - PID 6304 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:47.969Z] 12:54:47     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:47.970Z] 12:54:47     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:52.750Z] 12:54:52     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:52.752Z] 12:54:52     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:52.753Z] 12:54:52     INFO - PID 6304 | console.error: (new Error("IndexedDB: main/doh-config getLastModified() IndexedDB:  execute() The application is shutting down", "resource://services-settings/IDBHelpers.jsm", 18))
[task 2023-02-10T12:54:52.754Z] 12:54:52     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:52.755Z] 12:54:52     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:52.758Z] 12:54:52     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:52.758Z] 12:54:52     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:53.859Z] 12:54:53     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:53.865Z] 12:54:53     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:53.865Z] 12:54:53     INFO - PID 6304 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2023-02-10T12:54:53.867Z] 12:54:53     INFO - PID 6304 | console.error: (new RemoteSettingsWorkerError("Error: Can't import when we've started shutting down.", "resource://services-settings/RemoteSettingsWorker.jsm", 46))
[task 2023-02-10T12:54:56.097Z] 12:54:56     INFO - PID 6304 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-02-10T12:54:56.099Z] 12:54:56     INFO - PID 6304 |           Blocker:  Waiting for ping task
[task 2023-02-10T12:54:56.099Z] 12:54:56     INFO - PID 6304 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-02-10T12:54:56.100Z] 12:54:56     INFO - PID 6304 |           State: (none)
[task 2023-02-10T12:54:56.100Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.101Z] 12:54:56     INFO - PID 6304 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-02-10T12:54:56.102Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-02-10T12:54:56.102Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-02-10T12:54:56.103Z] 12:54:56     INFO - PID 6304 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-02-10T12:54:56.103Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-02-10T12:54:56.104Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-02-10T12:54:56.105Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-02-10T12:54:56.106Z] 12:54:56     INFO - PID 6304 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-02-10T12:54:56.106Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-02-10T12:54:56.107Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-02-10T12:54:56.108Z] 12:54:56     INFO - PID 6304 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-02-10T12:54:56.108Z] 12:54:56     INFO - PID 6304 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-02-10T12:54:56.109Z] 12:54:56     INFO - PID 6304 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-02-10T12:54:56.109Z] 12:54:56     INFO - PID 6304 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-02-10T12:54:56.110Z] 12:54:56     INFO - PID 6304 |           Blocker:  Waiting for ping task
[task 2023-02-10T12:54:56.111Z] 12:54:56     INFO - PID 6304 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-02-10T12:54:56.111Z] 12:54:56     INFO - PID 6304 |           State: (none)
[task 2023-02-10T12:54:56.112Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.113Z] 12:54:56     INFO - PID 6304 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-02-10T12:54:56.113Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-02-10T12:54:56.114Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-02-10T12:54:56.115Z] 12:54:56     INFO - PID 6304 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-02-10T12:54:56.115Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-02-10T12:54:56.116Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-02-10T12:54:56.116Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-02-10T12:54:56.117Z] 12:54:56     INFO - PID 6304 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-02-10T12:54:56.117Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-02-10T12:54:56.118Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-02-10T12:54:56.118Z] 12:54:56     INFO - PID 6304 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-02-10T12:54:56.119Z] 12:54:56     INFO - PID 6304 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-02-10T12:54:56.119Z] 12:54:56     INFO - PID 6304 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-02-10T12:54:56.120Z] 12:54:56     INFO - PID 6304 |           Blocker:  TelemetryController: shutting down
[task 2023-02-10T12:54:56.120Z] 12:54:56     INFO - PID 6304 |           Phase: profile-before-change-telemetry
[task 2023-02-10T12:54:56.122Z] 12:54:56     INFO - PID 6304 |           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-02-10T12:54:56.122Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-02-10T12:54:56.123Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-02-10T12:54:56.123Z] 12:54:56     INFO - PID 6304 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-02-10T12:54:56.124Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-02-10T12:54:56.124Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-02-10T12:54:56.125Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-02-10T12:54:56.125Z] 12:54:56     INFO - PID 6304 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-02-10T12:54:56.126Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-02-10T12:54:56.126Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-02-10T12:54:56.127Z] 12:54:56     INFO - PID 6304 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-02-10T12:54:56.127Z] 12:54:56     INFO - PID 6304 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-02-10T12:54:56.128Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.128Z] 12:54:56     INFO - PID 6304 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-02-10T12:54:56.129Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-02-10T12:54:56.129Z] 12:54:56     INFO - PID 6304 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-02-10T12:54:56.129Z] 12:54:56     INFO - PID 6304 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-02-10T12:54:56.130Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-02-10T12:54:56.131Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-02-10T12:54:56.131Z] 12:54:56     INFO - PID 6304 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-02-10T12:54:56.132Z] 12:54:56     INFO - PID 6304 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-02-10T12:54:56.132Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-02-10T12:54:56.132Z] 12:54:56     INFO - PID 6304 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-02-10T12:54:56.133Z] 12:54:56     INFO - PID 6304 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:828:36
[task 2023-02-10T12:54:56.134Z] 12:54:56     INFO - PID 6304 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-02-10T12:54:56.460Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.465Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.466Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.467Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.468Z] 12:54:56     INFO - PID 6304 | 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-02-10T12:54:56.541Z] 12:54:56     INFO - Browser exited with return code 0
[task 2023-02-10T12:54:56.545Z] 12:54:56     INFO - Closing logging queue
[task 2023-02-10T12:54:56.545Z] 12:54:56     INFO - queue closed
[task 2023-02-10T12:54:56.579Z] 12:54:56     INFO - Application command: Z:\task_167603007853985\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167603007853985\AppData\Local\Temp\tmpq1cdzwng
[task 2023-02-10T12:54:56.583Z] 12:54:56     INFO - PID 1876 | 1676033672593	Marionette	INFO	Marionette enabled
[task 2023-02-10T12:54:56.586Z] 12:54:56     INFO - PID 1876 | 1676033672595	Marionette	INFO	Listening on port 59020
[task 2023-02-10T12:54:56.587Z] 12:54:56     INFO - PID 1876 | JavaScript error: resource://gre/modules/XULStore.jsm, line 58: Error: Can't find profile directory.
[task 2023-02-10T12:54:56.588Z] 12:54:56     INFO - PID 1876 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167603007853985\\AppData\\Local\\Temp\\tmp3re4dkr4\\search.json.mozlz4", (void 0)))
[task 2023-02-10T12:54:56.589Z] 12:54:56     INFO - PID 1876 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:56.589Z] 12:54:56     INFO - PID 1876 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:56.590Z] 12:54:56     INFO - PID 1876 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:56.591Z] 12:54:56     INFO - PID 1876 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-10T12:54:56.592Z] 12:54:56     INFO - Starting runner
[task 2023-02-10T12:54:57.477Z] 12:54:57     INFO - TEST-START | /svg/historical.html

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