Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=414960536&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OYe_exhGQ5KmJvyzyAX2Vw/runs/0/artifacts/public/logs/live_backing.log
[task 2023-05-08T18:46:37.786Z] 18:46:37 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/take_screenshot/user_prompts.py::test_accept_and_notify[capabilities0-alert-None]
[task 2023-05-08T18:46:37.788Z] 18:46:37 INFO - PID 2254 | 1683571597785 Marionette DEBUG 0 -> [0,77,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2023-05-08T18:46:37.789Z] 18:46:37 INFO - PID 2254 | 1683571597785 Marionette INFO Stopped listening on port 40992
[task 2023-05-08T18:46:37.790Z] 18:46:37 INFO - PID 2254 | 1683571597787 Marionette TRACE [11] MarionetteCommands actor destroyed for window id 8589934595
[task 2023-05-08T18:46:37.827Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.829Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.850Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.851Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.854Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.855Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.857Z] 18:46:37 INFO - PID 2254 | [Child 2949, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.876Z] 18:46:37 INFO - PID 2254 | [CodeCoverage] Setting handlers for process 3079.
[task 2023-05-08T18:46:37.889Z] 18:46:37 INFO - PID 2254 | 1683571597888 Marionette TRACE Received observer notification quit-application
[task 2023-05-08T18:46:37.894Z] 18:46:37 INFO - PID 2254 | 1683571597893 Marionette TRACE Received observer notification quit-application
[task 2023-05-08T18:46:37.895Z] 18:46:37 INFO - PID 2254 | 1683571597893 Marionette DEBUG Marionette stopped listening
[task 2023-05-08T18:46:37.896Z] 18:46:37 INFO - PID 2254 | 1683571597895 Marionette DEBUG 0 <- [1,77,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2023-05-08T18:46:37.928Z] 18:46:37 INFO - PID 2254 | [Child 3043, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (MarionetteCommands, MarionetteCommandsParent:executeScript) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-08T18:46:37.933Z] 18:46:37 INFO - PID 2254 | 1683571597932 webdriver::server DEBUG Teardown session
[task 2023-05-08T18:46:37.941Z] 18:46:37 INFO - PID 2254 | 1683571597940 Marionette DEBUG Closed connection 0
[task 2023-05-08T18:46:38.013Z] 18:46:38 INFO - PID 2254 | [CodeCoverage] Setting handlers for process 3080.
[task 2023-05-08T18:46:40.335Z] 18:46:40 INFO - PID 2254 | 1683571600334 geckodriver::browser DEBUG Browser process stopped: exit status: 0
[task 2023-05-08T18:46:40.336Z] 18:46:40 INFO - PID 2254 | 1683571600335 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-05-08T18:46:40.337Z] 18:46:40 INFO - PID 2254 | 1683571600336 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/tmp/tmp51mmv57y.mozrunner"], "binary": "/builds/worker/workspace/build/application/firefox/firefox"}, "unhandledPromptBehavior": "accept and notify"}}}
[task 2023-05-08T18:46:40.338Z] 18:46:40 INFO - PID 2254 | 1683571600336 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2023-05-08T18:46:40.339Z] 18:46:40 INFO - PID 2254 | 1683571600336 geckodriver::capabilities DEBUG Found version 115.0a1
[task 2023-05-08T18:46:40.339Z] 18:46:40 INFO - PID 2254 | 1683571600337 geckodriver::browser DEBUG Backing up prefs to "/tmp/tmp51mmv57y.mozrunner/user.geckodriver_backup"
[task 2023-05-08T18:46:40.343Z] 18:46:40 INFO - PID 2254 | 1683571600342 mozrunner::runner INFO Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/builds/worker/workspace/build/application/firefox/firefox" "--marionette" "--profile" "/tmp/tmp51mmv57y.mozrunner" "-no-remote"
[task 2023-05-08T18:46:40.345Z] 18:46:40 INFO - PID 2254 | 1683571600343 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1
[task 2023-05-08T18:46:40.345Z] 18:46:40 INFO - PID 2254 | 1683571600343 geckodriver::browser TRACE Failed to open /tmp/tmp51mmv57y.mozrunner/MarionetteActivePort
[task 2023-05-08T18:46:40.345Z] 18:46:40 INFO - PID 2254 | 1683571600343 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-05-08T18:46:40.402Z] 18:46:40 INFO - PID 2254 | [CodeCoverage] Setting handlers for process 3155.
[task 2023-05-08T18:46:40.403Z] 18:46:40 INFO - PID 2254 | *** You are running in headless mode.
[task 2023-05-08T18:46:40.444Z] 18:46:40 INFO - PID 2254 | 1683571600443 geckodriver::browser TRACE Failed to open /tmp/tmp51mmv57y.mozrunner/MarionetteActivePort
[task 2023-05-08T18:46:40.445Z] 18:46:40 INFO - PID 2254 | 1683571600443 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-05-08T18:46:40.545Z] 18:46:40 INFO - PID 2254 | 1683571600543 geckodriver::browser TRACE Failed to open /tmp/tmp51mmv57y.mozrunner/MarionetteActivePort
[task 2023-05-08T18:46:40.545Z] 18:46:40 INFO - PID 2254 | 1683571600543 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-05-08T18:46:40.615Z] 18:46:40 INFO - PID 2254 | 1683571600614 Marionette INFO Marionette enabled
[task 2023-05-08T18:46:40.616Z] 18:46:40 INFO - PID 2254 | 1683571600615 Marionette TRACE Received observer notification final-ui-startup
[task 2023-05-08T18:46:40.618Z] 18:46:40 INFO - PID 2254 | 1683571600616 Marionette INFO Listening on port 46538
[task 2023-05-08T18:46:40.618Z] 18:46:40 INFO - PID 2254 | 1683571600617 Marionette DEBUG Marionette is listening
[task 2023-05-08T18:46:40.644Z] 18:46:40 INFO - PID 2254 | Read port: 46538
[task 2023-05-08T18:46:40.663Z] 18:46:40 INFO - PID 2254 | 1683571600662 Marionette DEBUG Accepted connection 0 from 127.0.0.1:44124
[task 2023-05-08T18:46:40.671Z] 18:46:40 INFO - PID 2254 | 1683571600671 geckodriver::marionette DEBUG Connection to Marionette established on 127.0.0.1:46538.
[task 2023-05-08T18:46:40.789Z] 18:46:40 INFO - PID 2254 | 1683571600788 Marionette DEBUG 0 -> [0,1,"WebDriver:NewSession",{"unhandledPromptBehavior":"accept and notify"}]
[task 2023-05-08T18:46:40.792Z] 18:46:40 INFO - PID 2254 | 1683571600791 Marionette DEBUG Waiting for initial application window
[task 2023-05-08T18:46:40.802Z] 18:46:40 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:40.804Z] 18:46:40 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.090Z] 18:46:41 INFO - PID 2254 | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2023-05-08T18:46:41.152Z] 18:46:41 INFO - PID 2254 | console.error: ({})
[task 2023-05-08T18:46:41.281Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.283Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.304Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.308Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.328Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.442Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.528Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.660Z] 18:46:41 INFO - PID 2254 | [CodeCoverage] Setting handlers for process 3211.
[task 2023-05-08T18:46:41.702Z] 18:46:41 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:41.973Z] 18:46:41 INFO - PID 2254 | [CodeCoverage] Setting handlers for process 3224.
[task 2023-05-08T18:46:42.082Z] 18:46:42 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:42.083Z] 18:46:42 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:42.084Z] 18:46:42 INFO - PID 2254 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-08T18:46:42.128Z] 18:46:42 INFO - PID 2254 | 1683571602127 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2023-05-08T18:46:42.135Z] 18:46:42 INFO - PID 2254 | 1683571602133 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=3200 waitForExplicitStart=false
[task 2023-05-08T18:46:42.135Z] 18:46:42 INFO - PID 2254 | 1683571602134 RemoteAgent TRACE [3] ProgressListener Document already loading about:blank
[task 2023-05-08T18:46:42.136Z] 18:46:42 INFO - PID 2254 | 1683571602134 RemoteAgent TRACE [3] ProgressListener Check loading state: isStart=true isStop=false
[task 2023-05-08T18:46:42.136Z] 18:46:42 INFO - PID 2254 | 1683571602134 RemoteAgent TRACE [3] ProgressListener state=start: about:blank
[task 2023-05-08T18:47:11.419Z] 18:47:11 INFO - PID 2254 | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 324))
[task 2023-05-08T18:52:38.485Z] 18:52:38 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/take_screenshot/user_prompts.py | expected OK
[task 2023-05-08T18:52:38.485Z] 18:52:38 INFO - TEST-INFO took 365003ms
[task 2023-05-08T18:52:38.487Z] 18:52:38 INFO - Restarting browser for new test group
[task 2023-05-08T18:52:38.674Z] 18:52:38 INFO - Closing logging queue
[task 2023-05-08T18:52:38.676Z] 18:52:38 INFO - queue closed
[task 2023-05-08T18:52:38.685Z] 18:52:38 INFO - PID 3303 | 1683571958684 geckodriver INFO Listening on 127.0.0.1:37006
[task 2023-05-08T18:52:38.686Z] 18:52:38 INFO - Starting runner
[task 2023-05-08T18:52:38.920Z] 18:52:38 INFO - TEST-START | /_mozilla/webdriver/bidi/script/exception_details.py
Description
•