Closed
Bug 1841802
Opened 3 years ago
Closed 3 years ago
Intermittent Wd TEST-UNEXPECTED-TIMEOUT | expected OK [hang after WARNING: DuplicateHandle failed for handle 0 in TransferHandles: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:621]
Categories
(Remote Protocol :: WebDriver BiDi, defect, P5)
Remote Protocol
WebDriver BiDi
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1832294
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=421551158&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Fw5HwUg4RK6XwkKigMzr9w/runs/0/artifacts/public/logs/live_backing.log
[task 2023-07-05T12:26:06.810Z] 12:26:06 INFO - STDOUT: PASSED
[task 2023-07-05T12:26:06.810Z] 12:26:06 INFO - STDOUT: 1688559966814 WebDriver BiDi DEBUG Connection fe9e48c8-d2b1-4f22-9c6b-5dd09ce6abde attached to session b32da023-b88f-4e15-bda8-eaa5da05cc6e
[task 2023-07-05T12:26:06.810Z] 12:26:06 INFO - STDOUT: 1688559966814 WebDriver BiDi DEBUG Waiting for initial application window
[task 2023-07-05T12:26:06.810Z] 12:26:06 INFO - STDOUT: 1688559966814 WebDriver BiDi DEBUG Registered session handler: /session/b32da023-b88f-4e15-bda8-eaa5da05cc6e
[task 2023-07-05T12:26:06.810Z] 12:26:06 INFO - STDOUT: tests/web-platform/mozilla/tests/webdriver/bidi/session/new/capabilities.py::test_proxy[alwaysMatch]
[task 2023-07-05T12:26:06.826Z] 12:26:06 INFO - STDOUT: 1688559966814 RemoteAgent DEBUG WebDriverBiDiConnection fe9e48c8-d2b1-4f22-9c6b-5dd09ce6abde <- {"id":1,"result":{"sessionId":"b32da023-b88f-4e15-bda8-eaa5da05cc6e","capabilities":{"browserName":"firefox","browserVersion":"117.0a1","platformName":"windows","acceptInsecureCerts":false,"proxy":{},"setWindowRect":true,"moz:accessibilityChecks":false,"moz:buildID":"20230705094648","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":6156,"moz:profile":"C:\\Users\\task_168855278886155\\AppData\\Local\\Temp\\tmpf0wm93ha","moz:shutdownTimeout":60000,"moz:windowless":false}}}
[task 2023-07-05T12:26:06.830Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent DEBUG WebDriverBiDiConnection fe9e48c8-d2b1-4f22-9c6b-5dd09ce6abde -> {"id":2,"method":"session.end","params":{}}
[task 2023-07-05T12:26:06.830Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent TRACE Created MessageHandler ROOT for session b32da023-b88f-4e15-bda8-eaa5da05cc6e
[task 2023-07-05T12:26:06.831Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent TRACE Module root/session.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.832Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent TRACE Received command session.end for destination ROOT
[task 2023-07-05T12:26:06.833Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent TRACE Module root/session.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966816 RemoteAgent TRACE Module root/session.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966817 RemoteAgent DEBUG WebDriverBiDiConnection fe9e48c8-d2b1-4f22-9c6b-5dd09ce6abde <- {"id":2,"result":{}}
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966817 WebDriver BiDi DEBUG Unregistered session handler: /session/b32da023-b88f-4e15-bda8-eaa5da05cc6e
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966817 RemoteAgent DEBUG WebDriverBiDiConnection fe9e48c8-d2b1-4f22-9c6b-5dd09ce6abde closed
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966818 RemoteAgent TRACE MessageHandler ROOT for session b32da023-b88f-4e15-bda8-eaa5da05cc6e is being destroyed
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966818 RemoteAgent TRACE Unregistered MessageHandler ROOT for session b32da023-b88f-4e15-bda8-eaa5da05cc6e
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966827 RemoteAgent INFO Perform WebSocket upgrade for incoming connection from 127.0.0.1:54365
[task 2023-07-05T12:26:06.834Z] 12:26:06 INFO - STDOUT: 1688559966828 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 accepted
[task 2023-07-05T12:26:06.843Z] 12:26:06 INFO - STDOUT: 1688559966829 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 -> {"id":1,"method":"session.new","params":{"capabilities":{"alwaysMatch":{"moz:firefoxOptions":{"args":["--profile","C:\\Users\\task_168855278886155\\AppData\\Local\\Temp\\tmp5wtj2xfi.mozrunner"]},"proxy":{"proxyType":"manual","httpProxy":"web-platform.test:8000"}}}}}
[task 2023-07-05T12:26:06.843Z] 12:26:06 INFO - STDOUT: 1688559966832 RemoteAgent INFO Proxy settings initialised: {"proxyType":"manual","httpProxy":"web-platform.test:8000"}
[task 2023-07-05T12:26:06.843Z] 12:26:06 INFO - STDOUT: 1688559966832 WebDriver BiDi DEBUG Connection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 attached to session b0978348-466a-419c-ae39-a76a7c072dbd
[task 2023-07-05T12:26:06.843Z] 12:26:06 INFO - STDOUT: 1688559966832 WebDriver BiDi DEBUG Waiting for initial application window
[task 2023-07-05T12:26:06.846Z] 12:26:06 INFO - STDOUT: 1688559966832 WebDriver BiDi DEBUG Registered session handler: /session/b0978348-466a-419c-ae39-a76a7c072dbd
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966832 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 <- {"id":1,"result":{"sessionId":"b0978348-466a-419c-ae39-a76a7c072dbd","capabilities":{"browserName":"firefox","browserVersion":"117.0a1","platformName":"windows","acceptInsecureCerts":false,"proxy":{"proxyType":"manual","httpProxy":"web-platform.test:8000"},"setWindowRect":true,"moz:accessibilityChecks":false,"moz:buildID":"20230705094648","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":6156,"moz:profile":"C:\\Users\\task_168855278886155\\AppData\\Local\\Temp\\tmpf0wm93ha","moz:shutdownTimeout":60000,"moz:windowless":false}}}
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966833 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 -> {"id":2,"method":"browsingContext.getTree","params":{}}
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966834 RemoteAgent TRACE Created MessageHandler ROOT for session b0978348-466a-419c-ae39-a76a7c072dbd
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966836 RemoteAgent TRACE Module root/browsingContext.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966836 RemoteAgent TRACE Received command browsingContext.getTree for destination ROOT
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966836 RemoteAgent TRACE Module root/browsingContext.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966836 RemoteAgent TRACE Module root/browsingContext.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966837 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 <- {"id":2,"result":{"contexts":[{"context":"cb2939c0-94c7-4b97-8564-a472e4268016","url":"about:blank","children":[],"parent":null}]}}
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966838 RemoteAgent DEBUG WebDriverBiDiConnection 7e4ab55f-681e-41f1-abc9-e5f55f2aff55 -> {"id":3,"method":"browsingContext.navigate","params":{"context":"cb2939c0-94c7-4b97-8564-a472e4268016","url":"http://example.com/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Eproxy%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8","wait":"complete"}}
[task 2023-07-05T12:26:06.847Z] 12:26:06 INFO - STDOUT: 1688559966838 RemoteAgent TRACE Module root/browsingContext.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966838 RemoteAgent TRACE Received command browsingContext.navigate for destination ROOT
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966838 RemoteAgent TRACE Module root/browsingContext.sys.mjs found for ROOT
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966839 RemoteAgent TRACE Received command browsingContext._getBaseURL for destination WINDOW_GLOBAL
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966839 RemoteAgent TRACE Module windowglobal-in-root/browsingContext.sys.mjs found for WINDOW_GLOBAL
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966840 RemoteAgent TRACE Module windowglobal/browsingContext.sys.mjs found for WINDOW_GLOBAL
[task 2023-07-05T12:26:06.858Z] 12:26:06 INFO - STDOUT: 1688559966840 RemoteAgent TRACE Module windowglobal-in-root/browsingContext.sys.mjs found for WINDOW_GLOBAL
[task 2023-07-05T12:26:07.047Z] 12:26:07 INFO - STDOUT: 1688559967048 RemoteAgent TRACE Created MessageHandler WINDOW_GLOBAL for session b0978348-466a-419c-ae39-a76a7c072dbd
[task 2023-07-05T12:26:07.051Z] 12:26:07 INFO - STDOUT: 1688559967049 RemoteAgent TRACE Received command browsingContext._getBaseURL for destination WINDOW_GLOBAL
[task 2023-07-05T12:26:07.052Z] 12:26:07 INFO - STDOUT: 1688559967050 RemoteAgent TRACE Module windowglobal/browsingContext.sys.mjs found for WINDOW_GLOBAL
[task 2023-07-05T12:26:07.052Z] 12:26:07 INFO - STDOUT: 1688559967051 RemoteAgent TRACE Module windowglobal/browsingContext.sys.mjs found for WINDOW_GLOBAL
[task 2023-07-05T12:26:07.062Z] 12:26:07 INFO - STDOUT: 1688559967055 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=true resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=true
[task 2023-07-05T12:26:07.063Z] 12:26:07 INFO - STDOUT: 1688559967055 RemoteAgent TRACE [3] ProgressListener Document already loading about:blank
[task 2023-07-05T12:26:07.063Z] 12:26:07 INFO - STDOUT: 1688559967055 RemoteAgent TRACE [3] ProgressListener Skip setting the unload timer
[task 2023-07-05T12:26:07.063Z] 12:26:07 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-07-05T12:26:07.079Z] 12:26:07 INFO - STDOUT: 1688559967077 RemoteAgent TRACE MessageHandler WINDOW_GLOBAL for session b0978348-466a-419c-ae39-a76a7c072dbd is being destroyed
[task 2023-07-05T12:26:07.090Z] 12:26:07 INFO - STDOUT: 1688559967089 RemoteAgent TRACE Unregistered MessageHandler WINDOW_GLOBAL for session b0978348-466a-419c-ae39-a76a7c072dbd
[task 2023-07-05T12:26:07.110Z] 12:26:07 INFO - STDOUT: 1688559967115 RemoteAgent TRACE [3] ProgressListener Check loading state: isStart=0 isStop=16
[task 2023-07-05T12:26:07.126Z] 12:26:07 INFO - STDOUT: [Parent 6156, IPC I/O Parent] WARNING: DuplicateHandle failed for handle 0 in TransferHandles: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:621
[task 2023-07-05T12:26:07.134Z] 12:26:07 INFO - STDOUT: [GPU 8268, IPC I/O Child] WARNING: pipe error: 232: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:443
[task 2023-07-05T12:26:30.104Z] 12:26:30 INFO - TEST-UNEXPECTED-TIMEOUT | /_mozilla/webdriver/bidi/session/new/capabilities.py | expected OK
[task 2023-07-05T12:26:30.104Z] 12:26:30 INFO - TEST-INFO took 30016ms
[task 2023-07-05T12:26:40.134Z] 12:26:40 WARNING - Forcibly terminating runner process
[task 2023-07-05T12:26:40.682Z] 12:26:40 INFO - PID 8988 | 1688560000198 geckodriver INFO Listening on 127.0.0.1:57404
[task 2023-07-05T12:26:40.684Z] 12:26:40 INFO - Starting runner
[task 2023-07-05T12:26:41.480Z] 12:26:41 INFO - TEST-START | /_mozilla/webdriver/bidi/session/new/first_match.py
|
||
Updated•3 years ago
|
Summary: Intermittent Wd TEST-UNEXPECTED-TIMEOUT | expected OK [hand after WARNING: DuplicateHandle failed for handle 0 in TransferHandles: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:621] → Intermittent Wd TEST-UNEXPECTED-TIMEOUT | expected OK [hang after WARNING: DuplicateHandle failed for handle 0 in TransferHandles: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:621]
|
||
Comment 1•3 years ago
|
||
This is a hang in browsingContext.navigate, and as such a dupe of 1832294.
You need to log in
before you can comment on or make changes to this bug.
Description
•