Closed Bug 1807584 Opened 2 years ago Closed 5 months ago

Intermittent /html/webappapis/animation-frames/callback-cross-realm-report-exception.html | single tracking bug

Categories

(Core :: DOM: Core & HTML, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox-esr102 --- unaffected
firefox108 --- unaffected
firefox109 --- unaffected
firefox110 --- wontfix
firefox111 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

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


[task 2022-12-26T06:14:34.308Z] 06:14:34     INFO - TEST-START | /html/webappapis/animation-frames/callback-cross-realm-report-exception.html
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - 
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - TEST-UNEXPECTED-FAIL | /html/webappapis/animation-frames/callback-cross-realm-report-exception.html | requestAnimationFrame() reports the exception from its callback in the callback's global object - assert_array_equals: lengths differ, expected array ["frame1"] length 1, got [] length 0
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - window.onload</<@http://web-platform.test:8000/html/webappapis/animation-frames/callback-cross-realm-report-exception.html:24:26
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - Test.prototype.step_timeout/<@http://web-platform.test:8000/resources/testharness.js:2716:25
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2596:25
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:2643:35
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - TEST-OK | /html/webappapis/animation-frames/callback-cross-realm-report-exception.html | took 303ms
[task 2022-12-26T06:14:34.611Z] 06:14:34     INFO - PID 1840 | 1672035274613	Marionette	INFO	Stopped listening on port 62157
[task 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 |           Blocker:  Waiting for ping task
[task 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 |           State: (none)
[task 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 | 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 2022-12-26T06:14:35.106Z] 06:14:35     INFO - PID 1840 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:712:15
[task 2022-12-26T06:14:35.114Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:517:26
[task 2022-12-26T06:14:35.114Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:456:15
[task 2022-12-26T06:14:35.116Z] 06:14:35     INFO - PID 1840 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2022-12-26T06:14:35.116Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2022-12-26T06:14:35.116Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-12-26T06:14:35.117Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2022-12-26T06:14:35.118Z] 06:14:35     INFO - PID 1840 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2022-12-26T06:14:35.118Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2022-12-26T06:14:35.118Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2022-12-26T06:14:35.120Z] 06:14:35     INFO - PID 1840 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2022-12-26T06:14:35.121Z] 06:14:35     INFO - PID 1840 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:566:16
[task 2022-12-26T06:14:35.127Z] 06:14:35     INFO - PID 1840 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-12-26T06:14:35.127Z] 06:14:35     INFO - PID 1840 |           Blocker:  Waiting for ping task
[task 2022-12-26T06:14:35.130Z] 06:14:35     INFO - PID 1840 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-12-26T06:14:35.132Z] 06:14:35     INFO - PID 1840 |           State: (none)
[task 2022-12-26T06:14:35.132Z] 06:14:35     INFO - PID 1840 | 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 2022-12-26T06:14:35.132Z] 06:14:35     INFO - PID 1840 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:712:15
[task 2022-12-26T06:14:35.133Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:517:26
[task 2022-12-26T06:14:35.134Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:456:15
[task 2022-12-26T06:14:35.134Z] 06:14:35     INFO - PID 1840 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2022-12-26T06:14:35.136Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2022-12-26T06:14:35.136Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-12-26T06:14:35.136Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2022-12-26T06:14:35.139Z] 06:14:35     INFO - PID 1840 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2022-12-26T06:14:35.140Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2022-12-26T06:14:35.140Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2022-12-26T06:14:35.142Z] 06:14:35     INFO - PID 1840 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2022-12-26T06:14:35.142Z] 06:14:35     INFO - PID 1840 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:566:16
[task 2022-12-26T06:14:35.143Z] 06:14:35     INFO - PID 1840 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-12-26T06:14:35.143Z] 06:14:35     INFO - PID 1840 |           Blocker:  TelemetryController: shutting down
[task 2022-12-26T06:14:35.144Z] 06:14:35     INFO - PID 1840 |           Phase: profile-before-change-telemetry
[task 2022-12-26T06:14:35.146Z] 06:14:35     INFO - PID 1840 |           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:712:15
[task 2022-12-26T06:14:35.146Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:517:26
[task 2022-12-26T06:14:35.147Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:456:15
[task 2022-12-26T06:14:35.148Z] 06:14:35     INFO - PID 1840 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2022-12-26T06:14:35.148Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2022-12-26T06:14:35.149Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-12-26T06:14:35.150Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2022-12-26T06:14:35.150Z] 06:14:35     INFO - PID 1840 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2022-12-26T06:14:35.150Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2022-12-26T06:14:35.150Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2022-12-26T06:14:35.153Z] 06:14:35     INFO - PID 1840 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2022-12-26T06:14:35.153Z] 06:14:35     INFO - PID 1840 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:566:16
[task 2022-12-26T06:14:35.154Z] 06:14:35     INFO - PID 1840 | 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 2022-12-26T06:14:35.154Z] 06:14:35     INFO - PID 1840 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:712:15
[task 2022-12-26T06:14:35.156Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:517:26
[task 2022-12-26T06:14:35.157Z] 06:14:35     INFO - PID 1840 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:456:15
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2022-12-26T06:14:35.158Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2022-12-26T06:14:35.162Z] 06:14:35     INFO - PID 1840 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2022-12-26T06:14:35.163Z] 06:14:35     INFO - PID 1840 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2022-12-26T06:14:35.164Z] 06:14:35     INFO - PID 1840 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:566:16
[task 2022-12-26T06:14:35.166Z] 06:14:35     INFO - PID 1840 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 712: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-12-26T06:14:35.169Z] 06:14:35     INFO - PID 1840 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 712: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-12-26T06:14:35.170Z] 06:14:35     INFO - PID 1840 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 712: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-12-26T06:14:35.171Z] 06:14:35     INFO - PID 1840 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 712: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-12-26T06:14:35.171Z] 06:14:35     INFO - PID 1840 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 712: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-12-26T06:14:35.489Z] 06:14:35     INFO - Browser exited with return code 0
[task 2022-12-26T06:14:35.493Z] 06:14:35     INFO - Closing logging queue
[task 2022-12-26T06:14:35.493Z] 06:14:35     INFO - queue closed
[task 2022-12-26T06:14:35.558Z] 06:14:35     INFO - Application command: Z:\task_167202528341832\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167202528341832\AppData\Local\Temp\tmp1kdo794u
[task 2022-12-26T06:14:35.566Z] 06:14:35     INFO - PID 8376 | 1672035273414	Marionette	INFO	Marionette enabled
[task 2022-12-26T06:14:35.567Z] 06:14:35     INFO - PID 8376 | 1672035273418	Marionette	INFO	Listening on port 62239
[task 2022-12-26T06:14:35.567Z] 06:14:35     INFO - PID 8376 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 237))
[task 2022-12-26T06:14:35.568Z] 06:14:35     INFO - PID 8376 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167202528341832\\AppData\\Local\\Temp\\tmprlubctew\\search.json.mozlz4", (void 0)))
[task 2022-12-26T06:14:35.569Z] 06:14:35     INFO - Starting runner
[task 2022-12-26T06:14:36.044Z] 06:14:36     INFO - PID 8376 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 237))
[task 2022-12-26T06:14:36.050Z] 06:14:36     INFO - PID 8376 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 237))
[task 2022-12-26T06:14:36.051Z] 06:14:36     INFO - PID 8376 | console.error: (new TypeError("NetworkError: Network request failed", "resource://services-settings/Utils.jsm", 237))
[task 2022-12-26T06:14:37.014Z] 06:14:37     INFO - TEST-START | /html/webappapis/animation-frames/callback-exception.html

First occurrence so far: see here

Seems related to Bug 1806612.

Regressed by: 1806612

Set release status flags based on info from the regressing bug 1806612

Set release status flags based on info from the regressing bug 1806612

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