Closed Bug 1822976 Opened 3 years ago Closed 3 years ago

Intermittent /loading/early-hints/iframe-x-frame-options-deny.h2.window.html | single tracking bug

Categories

(Testing :: web-platform-tests, defect, P5)

Product:
Testing
Component:
web-platform-tests
Type:
defect

Tracking

(Not tracked)

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=409245729&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KTQen5KTTeaBXnxV9de9rQ/runs/0/artifacts/public/logs/live_backing.log

task 2023-03-17T07:09:58.190Z] 07:09:58     INFO - TEST-START | /loading/early-hints/iframe-x-frame-options-deny.h2.window.html
[task 2023-03-17T07:09:58.192Z] 07:09:58     INFO - Closing window e6150aee-382f-47a6-8001-e5b474b30094
[task 2023-03-17T07:10:03.818Z] 07:10:03     INFO - PID 268 | 1679037003820	Marionette	WARN	Ignoring event 'pageshow' because document has an invalid readyState of 'uninitialized'.
[task 2023-03-17T07:10:03.866Z] 07:10:03     INFO - 
[task 2023-03-17T07:10:03.866Z] 07:10:03     INFO - TEST-UNEXPECTED-FAIL | /loading/early-hints/iframe-x-frame-options-deny.h2.window.html | Early hints for an iframe that violates X-Frame-Options should be ignored. - step_wait_func: Timed out waiting on condition
[task 2023-03-17T07:10:03.882Z] 07:10:03     INFO - TEST-OK | /loading/early-hints/iframe-x-frame-options-deny.h2.window.html | took 5682ms
[task 2023-03-17T07:10:03.884Z] 07:10:03     INFO - PID 268 | 1679037003882	Marionette	INFO	Stopped listening on port 56985
[task 2023-03-17T07:10:04.478Z] 07:10:04     INFO - PID 268 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-17T07:10:04.486Z] 07:10:04     INFO - PID 268 |           Blocker:  Waiting for ping task
[task 2023-03-17T07:10:04.487Z] 07:10:04     INFO - PID 268 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-17T07:10:04.487Z] 07:10:04     INFO - PID 268 |           State: (none)
[task 2023-03-17T07:10:04.488Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.488Z] 07:10:04     INFO - PID 268 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-17T07:10:04.489Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-17T07:10:04.489Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-17T07:10:04.490Z] 07:10:04     INFO - PID 268 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-17T07:10:04.490Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-17T07:10:04.491Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-17T07:10:04.492Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-17T07:10:04.492Z] 07:10:04     INFO - PID 268 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-17T07:10:04.493Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-17T07:10:04.494Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-17T07:10:04.495Z] 07:10:04     INFO - PID 268 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-17T07:10:04.495Z] 07:10:04     INFO - PID 268 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-17T07:10:04.496Z] 07:10:04     INFO - PID 268 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-17T07:10:04.498Z] 07:10:04     INFO - PID 268 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-17T07:10:04.498Z] 07:10:04     INFO - PID 268 |           Blocker:  Waiting for ping task
[task 2023-03-17T07:10:04.499Z] 07:10:04     INFO - PID 268 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-17T07:10:04.500Z] 07:10:04     INFO - PID 268 |           State: (none)
[task 2023-03-17T07:10:04.500Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.501Z] 07:10:04     INFO - PID 268 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-17T07:10:04.502Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-17T07:10:04.503Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-17T07:10:04.504Z] 07:10:04     INFO - PID 268 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-17T07:10:04.504Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-17T07:10:04.505Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-17T07:10:04.506Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-17T07:10:04.507Z] 07:10:04     INFO - PID 268 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-17T07:10:04.507Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-17T07:10:04.508Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-17T07:10:04.509Z] 07:10:04     INFO - PID 268 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-17T07:10:04.510Z] 07:10:04     INFO - PID 268 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-17T07:10:04.510Z] 07:10:04     INFO - PID 268 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-17T07:10:04.511Z] 07:10:04     INFO - PID 268 |           Blocker:  TelemetryController: shutting down
[task 2023-03-17T07:10:04.512Z] 07:10:04     INFO - PID 268 |           Phase: profile-before-change-telemetry
[task 2023-03-17T07:10:04.513Z] 07:10:04     INFO - PID 268 |           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-17T07:10:04.514Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-17T07:10:04.514Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-17T07:10:04.515Z] 07:10:04     INFO - PID 268 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-17T07:10:04.516Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-17T07:10:04.516Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-17T07:10:04.517Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-17T07:10:04.518Z] 07:10:04     INFO - PID 268 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-17T07:10:04.518Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-17T07:10:04.519Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-17T07:10:04.520Z] 07:10:04     INFO - PID 268 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-17T07:10:04.521Z] 07:10:04     INFO - PID 268 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-17T07:10:04.521Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.523Z] 07:10:04     INFO - PID 268 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-17T07:10:04.523Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-17T07:10:04.524Z] 07:10:04     INFO - PID 268 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-17T07:10:04.525Z] 07:10:04     INFO - PID 268 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-17T07:10:04.525Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-17T07:10:04.526Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-17T07:10:04.526Z] 07:10:04     INFO - PID 268 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-17T07:10:04.527Z] 07:10:04     INFO - PID 268 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-17T07:10:04.528Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-17T07:10:04.528Z] 07:10:04     INFO - PID 268 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-17T07:10:04.529Z] 07:10:04     INFO - PID 268 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:824:36
[task 2023-03-17T07:10:04.530Z] 07:10:04     INFO - PID 268 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-17T07:10:04.531Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.532Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.533Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.534Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.535Z] 07:10:04     INFO - PID 268 | 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-17T07:10:04.589Z] 07:10:04     INFO - Browser exited with return code 0
[task 2023-03-17T07:10:04.592Z] 07:10:04     INFO - Closing logging queue
[task 2023-03-17T07:10:04.592Z] 07:10:04     INFO - queue closed
[task 2023-03-17T07:10:04.859Z] 07:10:04     INFO - Application command: Z:\task_167902866114181\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167902866114181\AppData\Local\Temp\tmpcyct0j96
[task 2023-03-17T07:10:04.870Z] 07:10:04     INFO - PID 4648 | 1679036993462	Marionette	INFO	Marionette enabled
[task 2023-03-17T07:10:04.871Z] 07:10:04     INFO - PID 4648 | 1679036993466	Marionette	INFO	Listening on port 56997
[task 2023-03-17T07:10:04.872Z] 07:10:04     INFO - PID 4648 | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 58: Error: Can't find profile directory.
[task 2023-03-17T07:10:04.873Z] 07:10:04     INFO - PID 4648 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167902866114181\\AppData\\Local\\Temp\\tmp74wlpfhe\\search.json.mozlz4", (void 0)))
[task 2023-03-17T07:10:04.874Z] 07:10:04     INFO - PID 4648 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-17T07:10:04.874Z] 07:10:04     INFO - PID 4648 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-17T07:10:04.876Z] 07:10:04     INFO - PID 4648 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-17T07:10:04.877Z] 07:10:04     INFO - PID 4648 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-17T07:10:04.877Z] 07:10:04     INFO - PID 4648 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-17T07:10:04.878Z] 07:10:04     INFO - Starting runner

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

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