1821129 - Intermittent /html/browsers/browsing-the-web/read-media/pageload-video.html | single tracking bug

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

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

---

[task 2023-03-08T18:49:01.825Z] 18:49:01     INFO - TEST-START | /html/browsers/browsing-the-web/read-media/pageload-video.html
[task 2023-03-08T18:49:01.830Z] 18:49:01     INFO - Closing window 5aacb324-d71c-443e-88c7-20b0fa648629
[task 2023-03-08T18:49:04.594Z] 18:49:04     INFO - PID 2047 | [Parent 2047, IPC I/O Parent] WARNING: process 2349 exited on signal 0: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:266
[task 2023-03-08T18:49:11.910Z] 18:49:11     INFO - 
[task 2023-03-08T18:49:11.910Z] 18:49:11     INFO - TEST-UNEXPECTED-TIMEOUT | /html/browsers/browsing-the-web/read-media/pageload-video.html | The document for a standalone media file should have one child in the body. - Test timed out
[task 2023-03-08T18:49:11.910Z] 18:49:11     INFO - TEST-UNEXPECTED-TIMEOUT | /html/browsers/browsing-the-web/read-media/pageload-video.html | expected OK
[task 2023-03-08T18:49:11.910Z] 18:49:11     INFO - TEST-INFO took 10086ms
[task 2023-03-08T18:49:11.912Z] 18:49:11     INFO - PID 2047 | 1678301351910	Marionette	INFO	Stopped listening on port 50950
[task 2023-03-08T18:49:12.662Z] 18:49:12     INFO - PID 2047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-08T18:49:12.663Z] 18:49:12     INFO - PID 2047 |           Blocker:  Waiting for ping task
[task 2023-03-08T18:49:12.663Z] 18:49:12     INFO - PID 2047 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-08T18:49:12.663Z] 18:49:12     INFO - PID 2047 |           State: (none)
[task 2023-03-08T18:49:12.664Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.664Z] 18:49:12     INFO - PID 2047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-08T18:49:12.665Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-08T18:49:12.665Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-08T18:49:12.666Z] 18:49:12     INFO - PID 2047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-08T18:49:12.666Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-08T18:49:12.666Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-08T18:49:12.667Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-08T18:49:12.667Z] 18:49:12     INFO - PID 2047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-08T18:49:12.668Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-08T18:49:12.668Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-08T18:49:12.669Z] 18:49:12     INFO - PID 2047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-08T18:49:12.669Z] 18:49:12     INFO - PID 2047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-08T18:49:12.670Z] 18:49:12     INFO - PID 2047 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-08T18:49:12.670Z] 18:49:12     INFO - PID 2047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-08T18:49:12.670Z] 18:49:12     INFO - PID 2047 |           Blocker:  Waiting for ping task
[task 2023-03-08T18:49:12.671Z] 18:49:12     INFO - PID 2047 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-08T18:49:12.671Z] 18:49:12     INFO - PID 2047 |           State: (none)
[task 2023-03-08T18:49:12.672Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.672Z] 18:49:12     INFO - PID 2047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-08T18:49:12.672Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-08T18:49:12.673Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-08T18:49:12.673Z] 18:49:12     INFO - PID 2047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-08T18:49:12.674Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-08T18:49:12.674Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-08T18:49:12.674Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-08T18:49:12.675Z] 18:49:12     INFO - PID 2047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-08T18:49:12.675Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-08T18:49:12.676Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-08T18:49:12.676Z] 18:49:12     INFO - PID 2047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-08T18:49:12.677Z] 18:49:12     INFO - PID 2047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-08T18:49:12.677Z] 18:49:12     INFO - PID 2047 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-08T18:49:12.677Z] 18:49:12     INFO - PID 2047 |           Blocker:  TelemetryController: shutting down
[task 2023-03-08T18:49:12.678Z] 18:49:12     INFO - PID 2047 |           Phase: profile-before-change-telemetry
[task 2023-03-08T18:49:12.678Z] 18:49:12     INFO - PID 2047 |           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-08T18:49:12.679Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-08T18:49:12.679Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-08T18:49:12.679Z] 18:49:12     INFO - PID 2047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-08T18:49:12.680Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-08T18:49:12.680Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-08T18:49:12.680Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-08T18:49:12.681Z] 18:49:12     INFO - PID 2047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-08T18:49:12.681Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-08T18:49:12.682Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-08T18:49:12.682Z] 18:49:12     INFO - PID 2047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-08T18:49:12.682Z] 18:49:12     INFO - PID 2047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-08T18:49:12.683Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.683Z] 18:49:12     INFO - PID 2047 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-08T18:49:12.684Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-08T18:49:12.684Z] 18:49:12     INFO - PID 2047 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-08T18:49:12.684Z] 18:49:12     INFO - PID 2047 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-08T18:49:12.685Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-08T18:49:12.685Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-08T18:49:12.686Z] 18:49:12     INFO - PID 2047 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-08T18:49:12.686Z] 18:49:12     INFO - PID 2047 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-08T18:49:12.686Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-08T18:49:12.687Z] 18:49:12     INFO - PID 2047 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-08T18:49:12.687Z] 18:49:12     INFO - PID 2047 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-08T18:49:12.687Z] 18:49:12     INFO - PID 2047 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-08T18:49:12.702Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.703Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.703Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.704Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.704Z] 18:49:12     INFO - PID 2047 | 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-08T18:49:12.869Z] 18:49:12     INFO - Browser exited with return code 0
[task 2023-03-08T18:49:12.870Z] 18:49:12     INFO - Closing logging queue
[task 2023-03-08T18:49:12.871Z] 18:49:12     INFO - queue closed
[task 2023-03-08T18:49:13.879Z] 18:49:13     INFO - Application command: /opt/worker/tasks/task_167830020743638/build/application/Firefox Nightly.app/Contents/MacOS/firefox --marionette about:blank -foreground -profile /var/folders/41/0wfbzkvj4dlf_qqdn_pr3g_h000014/T/tmpbdd31mvc
[task 2023-03-08T18:49:13.886Z] 18:49:13     INFO - PID 2063 | 1678300931885	Marionette	INFO	Marionette enabled
[task 2023-03-08T18:49:13.887Z] 18:49:13     INFO - PID 2063 | 1678300931931	Marionette	INFO	Listening on port 50976
[task 2023-03-08T18:49:13.887Z] 18:49:13     INFO - PID 2063 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /var/folders/41/0wfbzkvj4dlf_qqdn_pr3g_h000014/T/tmpnpwbaybu/search.json.mozlz4", (void 0)))
[task 2023-03-08T18:49:13.888Z] 18:49:13     INFO - PID 2063 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-08T18:49:13.888Z] 18:49:13     INFO - PID 2063 | [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-03-08T18:49:13.889Z] 18:49:13     INFO - PID 2063 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-08T18:49:13.889Z] 18:49:13     INFO - PID 2063 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-08T18:49:13.890Z] 18:49:13     INFO - PID 2063 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-08T18:49:13.890Z] 18:49:13     INFO - PID 2063 | 2023-03-08 18:42:41.794 firefox[2063:42012] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
[task 2023-03-08T18:49:13.891Z] 18:49:13     INFO - PID 2063 | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 325))
[task 2023-03-08T18:49:13.891Z] 18:49:13     INFO - PID 2063 | 1678301322338	addons.xpi	ERROR	System addon update list error Error: Failed downloading XML, status: 0, reason: error
[task 2023-03-08T18:49:13.892Z] 18:49:13     INFO - Starting runner
[task 2023-03-08T18:49:23.367Z] 18:49:23     INFO - TEST-START | /html/browsers/browsing-the-web/read-text/load-text-plain.html

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

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

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-release: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1821129&startday=2023-04-10&endday=2023-04-16&tree=all

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1821129&startday=2023-04-24&endday=2023-04-30&tree=all

Comment 5

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

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