Closed
Bug 1830564
Opened 2 years ago
Closed 2 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/input/perform_actions/key.py | expected OK
Categories
(Remote Protocol :: WebDriver BiDi, defect, P5)
Remote Protocol
WebDriver BiDi
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1791951
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=414134560&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SDhe1nCzQ8eHEz5MkIMH6A/runs/0/artifacts/public/logs/live_backing.log
[task 2023-04-28T16:38:57.015Z] 16:38:57 INFO - STDOUT: PASSED
[task 2023-04-28T16:38:57.017Z] 16:38:57 INFO - PID 1020 | 1682699937016 RemoteAgent DEBUG WebDriverBiDiConnection 5e54950a-f34a-4310-b402-793be1269d47 -> {"id":695,"method":"input.releaseActions","params":{"context":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}}
[task 2023-04-28T16:38:57.019Z] 16:38:57 INFO - PID 1020 | 1682699937016 RemoteAgent TRACE Received command input.releaseActions for destination ROOT
[task 2023-04-28T16:38:57.026Z] 16:38:57 INFO - PID 1020 | 1682699937025 RemoteAgent TRACE Received command input.releaseActions for destination WINDOW_GLOBAL
[task 2023-04-28T16:38:57.030Z] 16:38:57 INFO - PID 1020 | 1682699937025 Marionette TRACE Dispatch KeyUpAction with key-0 a
[task 2023-04-28T16:38:57.031Z] 16:38:57 INFO - PID 1020 | 1682699937028 RemoteAgent DEBUG WebDriverBiDiConnection 5e54950a-f34a-4310-b402-793be1269d47 <- {"id":695,"result":{}}
[task 2023-04-28T16:38:57.039Z] 16:38:57 INFO - PID 1020 | 1682699937034 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/timeouts {"implicit": 0}
[task 2023-04-28T16:38:57.040Z] 16:38:57 INFO - PID 1020 | 1682699937035 RemoteAgent DEBUG WebDriverBiDiConnection 5e54950a-f34a-4310-b402-793be1269d47 closed
[task 2023-04-28T16:38:57.041Z] 16:38:57 INFO - PID 1020 | 1682699937036 Marionette DEBUG 0 -> [0,1572,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-04-28T16:38:57.041Z] 16:38:57 INFO - PID 1020 | 1682699937037 Marionette DEBUG 0 <- [1,1572,null,{"value":null}]
[task 2023-04-28T16:38:57.042Z] 16:38:57 INFO - PID 1020 | 1682699937038 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.043Z] 16:38:57 INFO - PID 1020 | 1682699937040 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/timeouts {"pageLoad": 300000}
[task 2023-04-28T16:38:57.043Z] 16:38:57 INFO - PID 1020 | 1682699937042 Marionette DEBUG 0 -> [0,1573,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-04-28T16:38:57.044Z] 16:38:57 INFO - PID 1020 | 1682699937043 Marionette DEBUG 0 <- [1,1573,null,{"value":null}]
[task 2023-04-28T16:38:57.053Z] 16:38:57 INFO - PID 1020 | 1682699937051 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.054Z] 16:38:57 INFO - PID 1020 | 1682699937052 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/timeouts {"script": 30000}
[task 2023-04-28T16:38:57.057Z] 16:38:57 INFO - PID 1020 | 1682699937055 Marionette DEBUG 0 -> [0,1574,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-04-28T16:38:57.058Z] 16:38:57 INFO - PID 1020 | 1682699937056 Marionette DEBUG 0 <- [1,1574,null,{"value":null}]
[task 2023-04-28T16:38:57.062Z] 16:38:57 INFO - PID 1020 | 1682699937061 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.063Z] 16:38:57 INFO - PID 1020 | 1682699937062 webdriver::server DEBUG -> GET /session/17beb64e-5efd-4cd9-906a-ff5728378748/window
[task 2023-04-28T16:38:57.066Z] 16:38:57 INFO - PID 1020 | 1682699937065 Marionette DEBUG 0 -> [0,1575,"WebDriver:GetWindowHandle",{}]
[task 2023-04-28T16:38:57.067Z] 16:38:57 INFO - PID 1020 | 1682699937065 Marionette DEBUG 0 <- [1,1575,null,{"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.068Z] 16:38:57 INFO - PID 1020 | 1682699937067 webdriver::server DEBUG <- 200 OK {"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.069Z] 16:38:57 INFO - PID 1020 | 1682699937068 webdriver::server DEBUG -> GET /session/17beb64e-5efd-4cd9-906a-ff5728378748/window
[task 2023-04-28T16:38:57.070Z] 16:38:57 INFO - PID 1020 | 1682699937070 Marionette DEBUG 0 -> [0,1576,"WebDriver:GetWindowHandle",{}]
[task 2023-04-28T16:38:57.071Z] 16:38:57 INFO - PID 1020 | 1682699937070 Marionette DEBUG 0 <- [1,1576,null,{"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.074Z] 16:38:57 INFO - PID 1020 | 1682699937071 webdriver::server DEBUG <- 200 OK {"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.074Z] 16:38:57 INFO - PID 1020 | 1682699937072 webdriver::server DEBUG -> GET /session/17beb64e-5efd-4cd9-906a-ff5728378748/window/handles
[task 2023-04-28T16:38:57.075Z] 16:38:57 INFO - PID 1020 | 1682699937074 Marionette DEBUG 0 -> [0,1577,"WebDriver:GetWindowHandles",{}]
[task 2023-04-28T16:38:57.076Z] 16:38:57 INFO - PID 1020 | 1682699937075 Marionette DEBUG 0 <- [1,1577,null,["a29653f5-91f4-48f8-ab3d-060e1af754cd"]]
[task 2023-04-28T16:38:57.078Z] 16:38:57 INFO - PID 1020 | 1682699937076 webdriver::server DEBUG <- 200 OK {"value":["a29653f5-91f4-48f8-ab3d-060e1af754cd"]}
[task 2023-04-28T16:38:57.079Z] 16:38:57 INFO - PID 1020 | 1682699937077 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/window {"handle": "a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.090Z] 16:38:57 INFO - PID 1020 | 1682699937084 Marionette DEBUG 0 -> [0,1578,"WebDriver:SwitchToWindow",{"handle":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.090Z] 16:38:57 INFO - PID 1020 | 1682699937086 Marionette DEBUG 0 <- [1,1578,null,{"value":null}]
[task 2023-04-28T16:38:57.091Z] 16:38:57 INFO - PID 1020 | 1682699937088 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.093Z] 16:38:57 INFO - PID 1020 | 1682699937089 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/alert/dismiss {}
[task 2023-04-28T16:38:57.096Z] 16:38:57 INFO - PID 1020 | 1682699937095 Marionette DEBUG 0 -> [0,1579,"WebDriver:DismissAlert",{}]
[task 2023-04-28T16:38:57.099Z] 16:38:57 INFO - PID 1020 | 1682699937097 Marionette DEBUG 0 <- [1,1579,{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8\nWebDriverError@chrome://remote/content/shared/webdriver/Er ... ote/content/marionette/server.sys.mjs:249:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"},null]
[task 2023-04-28T16:38:57.101Z] 16:38:57 INFO - PID 1020 | 1682699937098 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/Remo ... ontent/marionette/server.sys.mjs:249:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"}}
[task 2023-04-28T16:38:57.102Z] 16:38:57 INFO - PID 1020 | 1682699937100 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/window {"handle": "a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.120Z] 16:38:57 INFO - PID 1020 | 1682699937118 Marionette DEBUG 0 -> [0,1580,"WebDriver:SwitchToWindow",{"handle":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.122Z] 16:38:57 INFO - PID 1020 | 1682699937121 Marionette DEBUG 0 <- [1,1580,null,{"value":null}]
[task 2023-04-28T16:38:57.123Z] 16:38:57 INFO - PID 1020 | 1682699937122 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.125Z] 16:38:57 INFO - PID 1020 | 1682699937124 webdriver::server DEBUG -> GET /session/17beb64e-5efd-4cd9-906a-ff5728378748/window
[task 2023-04-28T16:38:57.127Z] 16:38:57 INFO - PID 1020 | 1682699937126 Marionette DEBUG 0 -> [0,1581,"WebDriver:GetWindowHandle",{}]
[task 2023-04-28T16:38:57.128Z] 16:38:57 INFO - PID 1020 | 1682699937127 Marionette DEBUG 0 <- [1,1581,null,{"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.131Z] 16:38:57 INFO - PID 1020 | 1682699937129 webdriver::server DEBUG <- 200 OK {"value":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.131Z] 16:38:57 INFO - PID 1020 | 1682699937130 webdriver::server DEBUG -> GET /session/17beb64e-5efd-4cd9-906a-ff5728378748/window/handles
[task 2023-04-28T16:38:57.133Z] 16:38:57 INFO - PID 1020 | 1682699937132 Marionette DEBUG 0 -> [0,1582,"WebDriver:GetWindowHandles",{}]
[task 2023-04-28T16:38:57.136Z] 16:38:57 INFO - PID 1020 | 1682699937134 Marionette DEBUG 0 <- [1,1582,null,["a29653f5-91f4-48f8-ab3d-060e1af754cd"]]
[task 2023-04-28T16:38:57.136Z] 16:38:57 INFO - PID 1020 | 1682699937134 webdriver::server DEBUG <- 200 OK {"value":["a29653f5-91f4-48f8-ab3d-060e1af754cd"]}
[task 2023-04-28T16:38:57.137Z] 16:38:57 INFO - PID 1020 | 1682699937136 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/window {"handle": "a29653f5-91f4-48f8-ab3d-060e1af754cd"}
[task 2023-04-28T16:38:57.141Z] 16:38:57 INFO - PID 1020 | 1682699937140 Marionette DEBUG 0 -> [0,1583,"WebDriver:SwitchToWindow",{"handle":"a29653f5-91f4-48f8-ab3d-060e1af754cd"}]
[task 2023-04-28T16:38:57.144Z] 16:38:57 INFO - PID 1020 | 1682699937143 Marionette DEBUG 0 <- [1,1583,null,{"value":null}]
[task 2023-04-28T16:38:57.145Z] 16:38:57 INFO - PID 1020 | 1682699937144 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.146Z] 16:38:57 INFO - PID 1020 | 1682699937145 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/window/rect {"width": 800, "height": 600}
[task 2023-04-28T16:38:57.147Z] 16:38:57 INFO - PID 1020 | 1682699937147 Marionette DEBUG 0 -> [0,1584,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2023-04-28T16:38:57.148Z] 16:38:57 INFO - PID 1020 | 1682699937148 Marionette TRACE Requested window geometry matches
[task 2023-04-28T16:38:57.150Z] 16:38:57 INFO - PID 1020 | 1682699937149 Marionette DEBUG 0 <- [1,1584,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2023-04-28T16:38:57.150Z] 16:38:57 INFO - PID 1020 | 1682699937150 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2023-04-28T16:38:57.152Z] 16:38:57 INFO - PID 1020 | 1682699937151 webdriver::server DEBUG -> POST /session/17beb64e-5efd-4cd9-906a-ff5728378748/frame {"id": null}
[task 2023-04-28T16:38:57.153Z] 16:38:57 INFO - PID 1020 | 1682699937152 Marionette DEBUG 0 -> [0,1585,"WebDriver:SwitchToFrame",{"id":null}]
[task 2023-04-28T16:38:57.158Z] 16:38:57 INFO - PID 1020 | 1682699937157 Marionette DEBUG 0 <- [1,1585,null,{"value":null}]
[task 2023-04-28T16:38:57.160Z] 16:38:57 INFO - PID 1020 | 1682699937158 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-04-28T16:38:57.171Z] 16:38:57 INFO - PID 1020 | 1682699937170 webdriver::server DEBUG -> DELETE /session/17beb64e-5efd-4cd9-906a-ff5728378748
[task 2023-04-28T16:38:57.173Z] 16:38:57 INFO - PID 1020 | 1682699937172 Marionette DEBUG 0 -> [0,1586,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2023-04-28T16:38:57.174Z] 16:38:57 INFO - PID 1020 | 1682699937173 Marionette INFO Stopped listening on port 45618
[task 2023-04-28T16:38:57.177Z] 16:38:57 INFO - PID 1020 | 1682699937176 Marionette TRACE [11] MarionetteCommands actor destroyed for window id 6442451042
[task 2023-04-28T16:38:57.185Z] 16:38:57 INFO - PID 1020 | 1682699937183 WebDriver BiDi DEBUG Unregistered session handler: /session/17beb64e-5efd-4cd9-906a-ff5728378748
[task 2023-04-28T16:38:57.195Z] 16:38:57 INFO - PID 1020 | 1682699937194 RemoteAgent TRACE MessageHandler ROOT for session 17beb64e-5efd-4cd9-906a-ff5728378748 is being destroyed
[task 2023-04-28T16:38:57.197Z] 16:38:57 INFO - PID 1020 | 1682699937195 RemoteAgent TRACE Unregistered MessageHandler ROOT for session 17beb64e-5efd-4cd9-906a-ff5728378748
[task 2023-04-28T16:38:57.334Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.336Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.357Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.366Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.368Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.369Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.371Z] 16:38:57 INFO - PID 1020 | [Child 17914, 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-04-28T16:38:57.509Z] 16:38:57 INFO - PID 1020 | 1682699937508 Marionette TRACE Received observer notification quit-application
[task 2023-04-28T16:38:57.519Z] 16:38:57 INFO - PID 1020 | 1682699937518 Marionette TRACE Received observer notification quit-application
[task 2023-04-28T16:38:57.520Z] 16:38:57 INFO - PID 1020 | 1682699937519 Marionette DEBUG Marionette stopped listening
[task 2023-04-28T16:38:57.521Z] 16:38:57 INFO - PID 1020 | 1682699937520 RemoteAgent TRACE Received observer notification quit-application
[task 2023-04-28T16:38:57.526Z] 16:38:57 INFO - PID 1020 | 1682699937525 Marionette DEBUG 0 <- [1,1586,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2023-04-28T16:38:57.662Z] 16:38:57 INFO - PID 1020 | 1682699937659 RemoteAgent TRACE MessageHandler WINDOW_GLOBAL for session 17beb64e-5efd-4cd9-906a-ff5728378748 is being destroyed
[task 2023-04-28T16:38:57.662Z] 16:38:57 INFO - PID 1020 | 1682699937661 RemoteAgent TRACE Unregistered MessageHandler WINDOW_GLOBAL for session 17beb64e-5efd-4cd9-906a-ff5728378748
[task 2023-04-28T16:38:57.679Z] 16:38:57 INFO - PID 1020 | 1682699937678 RemoteAgent DEBUG Resetting recommended pref browser.contentblocking.features.standard
[task 2023-04-28T16:38:57.680Z] 16:38:57 INFO - PID 1020 | 1682699937678 RemoteAgent DEBUG Resetting recommended pref network.cookie.cookieBehavior
[task 2023-04-28T16:38:57.683Z] 16:38:57 INFO - PID 1020 | 1682699937680 webdriver::server DEBUG Teardown session
[task 2023-04-28T16:38:57.705Z] 16:38:57 INFO - PID 1020 | 1682699937703 Marionette DEBUG Closed connection 0
[task 2023-04-28T16:38:57.935Z] 16:38:57 INFO - PID 1020 | *** You are running in background task mode. ***
[task 2023-04-28T16:38:57.935Z] 16:38:57 INFO - PID 1020 | *** You are running in headless mode.
[task 2023-04-28T16:38:58.449Z] 16:38:58 INFO - PID 1020 | console.error: "/tmp/tmph7b05mzk.mozrunner/storage" "to-be-removed" 0 "" ""
[task 2023-04-28T16:38:58.455Z] 16:38:58 INFO - PID 1020 | console.error: "started removing /tmp/tmph7b05mzk.mozrunner/storage/to-be-removed"
[task 2023-04-28T16:38:58.456Z] 16:38:58 INFO - PID 1020 | console.error: "done removing /tmp/tmph7b05mzk.mozrunner/storage/to-be-removed. removed 1 entries."
[task 2023-04-28T16:38:58.458Z] 16:38:58 INFO - PID 1020 | console.warn: "Skipping Glean as no metrics id is passed"
[task 2023-04-28T16:38:58.477Z] 16:38:58 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/input/perform_actions/key.py | expected OK
[task 2023-04-28T16:38:58.477Z] 16:38:58 INFO - TEST-INFO took 80002ms
[task 2023-04-28T16:38:58.712Z] 16:38:58 INFO - Closing logging queue
[task 2023-04-28T16:38:58.713Z] 16:38:58 INFO - queue closed
[task 2023-04-28T16:38:58.726Z] 16:38:58 INFO - PID 18143 | 1682699938724 geckodriver INFO Listening on 127.0.0.1:41512
[task 2023-04-28T16:38:58.727Z] 16:38:58 INFO - Starting runner
[task 2023-04-28T16:38:58.983Z] 16:38:58 INFO - TEST-START | /webdriver/tests/bidi/input/perform_actions/key_modifier.py
| Comment hidden (Intermittent Failures Robot) |
The initial launch of Firefox took quite some time for these particular TSAN builds. So it's basically a dupe of bug 1791951.
You need to log in
before you can comment on or make changes to this bug.
Description
•