Closed
Bug 1848314
Opened 1 year ago
Closed 1 year ago
Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/session/unsubscribe/invalid.py | expected OK
Categories
(Remote Protocol :: WebDriver BiDi, defect, P5)
Remote Protocol
WebDriver BiDi
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1630162
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=425664531&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MhebzBaiQZulfUJOaNXWDA/runs/0/artifacts/public/logs/live_backing.log
[task 2023-08-11T10:20:40.971Z] 10:20:40 INFO - TEST-START | /webdriver/tests/bidi/session/unsubscribe/invalid.py
[task 2023-08-11T10:20:41.027Z] 10:20:41 INFO - STDOUT: ============================= test session starts ==============================
[task 2023-08-11T10:20:41.029Z] 10:20:41 INFO - STDOUT: platform linux -- Python 3.7.5, pytest-7.0.1, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2023-08-11T10:20:41.030Z] 10:20:41 INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2023-08-11T10:20:41.030Z] 10:20:41 INFO - STDOUT: plugins: asyncio-0.19.0
[task 2023-08-11T10:20:41.030Z] 10:20:41 INFO - STDOUT: asyncio: mode=strict
[task 2023-08-11T10:20:41.031Z] 10:20:41 INFO - STDOUT: collecting ...
[task 2023-08-11T10:20:41.050Z] 10:20:41 INFO - STDOUT: collected 34 items
[task 2023-08-11T10:20:41.050Z] 10:20:41 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/session/unsubscribe/invalid.py::test_params_empty
[task 2023-08-11T10:20:41.052Z] 10:20:41 INFO - PID 6397 | 1691749241050 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/tmp/tmp_batu529.mozrunner"]}, "webSocketUrl": true}}}
[task 2023-08-11T10:20:41.052Z] 10:20:41 INFO - PID 6397 | 1691749241051 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2023-08-11T10:20:41.053Z] 10:20:41 INFO - PID 6397 | 1691749241051 geckodriver::capabilities DEBUG Found version 118.0a1
[task 2023-08-11T10:20:41.053Z] 10:20:41 INFO - PID 6397 | 1691749241052 geckodriver::browser DEBUG Backing up prefs to "/tmp/tmp_batu529.mozrunner/user.geckodriver_backup"
[task 2023-08-11T10:20:41.059Z] 10:20:41 INFO - PID 6397 | 1691749241057 mozrunner::runner INFO Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/bui ... te" "--profile" "/tmp/tmp_batu529.mozrunner" "--remote-debugging-port" "9222" "--remote-allow-hosts" "localhost" "-no-remote"
[task 2023-08-11T10:20:41.059Z] 10:20:41 INFO - PID 6397 | 1691749241058 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1
[task 2023-08-11T10:20:41.060Z] 10:20:41 INFO - PID 6397 | 1691749241058 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.061Z] 10:20:41 INFO - PID 6397 | 1691749241058 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.106Z] 10:20:41 INFO - PID 6397 | *** You are running in headless mode.
[task 2023-08-11T10:20:41.159Z] 10:20:41 INFO - PID 6397 | 1691749241158 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.160Z] 10:20:41 INFO - PID 6397 | 1691749241158 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.259Z] 10:20:41 INFO - PID 6397 | 1691749241258 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.259Z] 10:20:41 INFO - PID 6397 | 1691749241258 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.359Z] 10:20:41 INFO - PID 6397 | 1691749241358 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.360Z] 10:20:41 INFO - PID 6397 | 1691749241358 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.459Z] 10:20:41 INFO - PID 6397 | 1691749241458 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.461Z] 10:20:41 INFO - PID 6397 | 1691749241458 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.559Z] 10:20:41 INFO - PID 6397 | 1691749241558 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.560Z] 10:20:41 INFO - PID 6397 | 1691749241558 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.659Z] 10:20:41 INFO - PID 6397 | 1691749241659 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.660Z] 10:20:41 INFO - PID 6397 | 1691749241659 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.759Z] 10:20:41 INFO - PID 6397 | 1691749241759 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.760Z] 10:20:41 INFO - PID 6397 | 1691749241759 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.859Z] 10:20:41 INFO - PID 6397 | 1691749241859 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.860Z] 10:20:41 INFO - PID 6397 | 1691749241859 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:41.960Z] 10:20:41 INFO - PID 6397 | 1691749241959 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:41.960Z] 10:20:41 INFO - PID 6397 | 1691749241959 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.060Z] 10:20:42 INFO - PID 6397 | 1691749242059 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.060Z] 10:20:42 INFO - PID 6397 | 1691749242059 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.160Z] 10:20:42 INFO - PID 6397 | 1691749242159 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.160Z] 10:20:42 INFO - PID 6397 | 1691749242159 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.260Z] 10:20:42 INFO - PID 6397 | 1691749242259 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.261Z] 10:20:42 INFO - PID 6397 | 1691749242259 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.360Z] 10:20:42 INFO - PID 6397 | 1691749242359 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.361Z] 10:20:42 INFO - PID 6397 | 1691749242359 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.461Z] 10:20:42 INFO - PID 6397 | 1691749242460 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.461Z] 10:20:42 INFO - PID 6397 | 1691749242460 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.561Z] 10:20:42 INFO - PID 6397 | 1691749242560 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.561Z] 10:20:42 INFO - PID 6397 | 1691749242560 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.661Z] 10:20:42 INFO - PID 6397 | 1691749242660 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.662Z] 10:20:42 INFO - PID 6397 | 1691749242660 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.681Z] 10:20:42 INFO - PID 6397 | 1691749242681 RemoteAgent DEBUG WebDriver BiDi enabled
[task 2023-08-11T10:20:42.683Z] 10:20:42 INFO - PID 6397 | 1691749242682 RemoteAgent DEBUG CDP enabled
[task 2023-08-11T10:20:42.685Z] 10:20:42 INFO - PID 6397 | 1691749242684 Marionette INFO Marionette enabled
[task 2023-08-11T10:20:42.689Z] 10:20:42 INFO - PID 6397 | 1691749242688 Marionette TRACE Received observer notification final-ui-startup
[task 2023-08-11T10:20:42.692Z] 10:20:42 INFO - PID 6397 | 1691749242691 RemoteAgent TRACE Received observer notification final-ui-startup
[task 2023-08-11T10:20:42.761Z] 10:20:42 INFO - PID 6397 | 1691749242760 geckodriver::browser TRACE Failed to open /tmp/tmp_batu529.mozrunner/MarionetteActivePort
[task 2023-08-11T10:20:42.761Z] 10:20:42 INFO - PID 6397 | 1691749242760 geckodriver::marionette TRACE Retrying in 100ms
[task 2023-08-11T10:20:42.833Z] 10:20:42 INFO - PID 6397 | 1691749242832 Marionette INFO Listening on port 45597
[task 2023-08-11T10:20:42.835Z] 10:20:42 INFO - PID 6397 | 1691749242834 Marionette DEBUG Marionette is listening
[task 2023-08-11T10:20:42.861Z] 10:20:42 INFO - PID 6397 | Read port: 45597
[task 2023-08-11T10:20:42.868Z] 10:20:42 INFO - PID 6397 | 1691749242867 RemoteAgent TRACE Available local IP addresses: 127.0.0.1, [::1]
[task 2023-08-11T10:20:42.879Z] 10:20:42 INFO - PID 6397 | WebDriver BiDi listening on ws://127.0.0.1:9222
[task 2023-08-11T10:20:42.881Z] 10:20:42 INFO - PID 6397 | 1691749242880 CDP DEBUG Waiting for initial application window
[task 2023-08-11T10:20:42.901Z] 10:20:42 INFO - PID 6397 | 1691749242900 Marionette DEBUG Accepted connection 0 from 127.0.0.1:56846
[task 2023-08-11T10:20:42.915Z] 10:20:42 INFO - PID 6397 | 1691749242914 geckodriver::marionette DEBUG Connection to Marionette established on 127.0.0.1:45597.
[task 2023-08-11T10:20:42.936Z] 10:20:42 INFO - PID 6397 | 1691749242935 Marionette DEBUG 0 -> [0,1,"WebDriver:NewSession",{"webSocketUrl":true}]
[task 2023-08-11T10:20:42.950Z] 10:20:42 INFO - PID 6397 | 1691749242949 WebDriver BiDi DEBUG Waiting for initial application window
[task 2023-08-11T10:20:43.513Z] 10:20:43 INFO - PID 6397 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-08-11T10:20:43.518Z] 10:20:43 INFO - PID 6397 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-08-11T10:20:44.853Z] 10:20:44 INFO - PID 6397 | Crash Annotation GraphicsCriticalError: |[0][GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt (t=3.78749) [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2023-08-11T10:20:44.971Z] 10:20:44 INFO - PID 6397 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-08-11T10:20:45.230Z] 10:20:45 INFO - PID 6397 | console.error: ({})
<...>
[task 2023-08-11T10:20:55.640Z] 10:20:55 INFO - PID 6397 | 1691749255637 RemoteAgent TRACE Received command log._applySessionData for destination WINDOW_GLOBAL
[task 2023-08-11T10:20:55.640Z] 10:20:55 INFO - PID 6397 | 1691749255637 RemoteAgent TRACE Module windowglobal-in-root/log.sys.mjs found for WINDOW_GLOBAL
[task 2023-08-11T10:20:55.641Z] 10:20:55 INFO - PID 6397 | 1691749255637 RemoteAgent TRACE Module windowglobal/log.sys.mjs found for WINDOW_GLOBAL
[task 2023-08-11T10:20:55.642Z] 10:20:55 INFO - PID 6397 | 1691749255639 RemoteAgent TRACE Received command log._applySessionData for destination WINDOW_GLOBAL
[task 2023-08-11T10:20:55.642Z] 10:20:55 INFO - PID 6397 | 1691749255639 RemoteAgent TRACE Module windowglobal/log.sys.mjs found for WINDOW_GLOBAL
[task 2023-08-11T10:20:55.643Z] 10:20:55 INFO - PID 6397 | 1691749255642 RemoteAgent TRACE Module root/log.sys.mjs found for ROOT
[task 2023-08-11T10:20:55.644Z] 10:20:55 INFO - PID 6397 | 1691749255644 RemoteAgent DEBUG WebDriverBiDiConnection 135b1677-b076-4c17-92ce-14ecba1e1c4c <- {"type":"success","id":58,"result":{}}
[task 2023-08-11T10:20:55.646Z] 10:20:55 INFO - PID 6397 | 1691749255646 RemoteAgent DEBUG WebDriverBiDiConnection 135b1677-b076-4c17-92ce-14ecba1e1c4c closed
[task 2023-08-11T10:20:55.648Z] 10:20:55 INFO - PID 6397 | 1691749255647 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/timeouts {"implicit": 0}
[task 2023-08-11T10:20:55.650Z] 10:20:55 INFO - PID 6397 | 1691749255649 Marionette DEBUG 0 -> [0,532,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-08-11T10:20:55.653Z] 10:20:55 INFO - PID 6397 | 1691749255650 Marionette DEBUG 0 <- [1,532,null,{"value":null}]
[task 2023-08-11T10:20:55.654Z] 10:20:55 INFO - PID 6397 | 1691749255653 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.655Z] 10:20:55 INFO - PID 6397 | 1691749255654 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/timeouts {"pageLoad": 300000}
[task 2023-08-11T10:20:55.656Z] 10:20:55 INFO - PID 6397 | 1691749255656 Marionette DEBUG 0 -> [0,533,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-08-11T10:20:55.657Z] 10:20:55 INFO - PID 6397 | 1691749255656 Marionette DEBUG 0 <- [1,533,null,{"value":null}]
[task 2023-08-11T10:20:55.659Z] 10:20:55 INFO - PID 6397 | 1691749255657 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.661Z] 10:20:55 INFO - PID 6397 | 1691749255658 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/timeouts {"script": 30000}
[task 2023-08-11T10:20:55.662Z] 10:20:55 INFO - PID 6397 | 1691749255660 Marionette DEBUG 0 -> [0,534,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-08-11T10:20:55.663Z] 10:20:55 INFO - PID 6397 | 1691749255660 Marionette DEBUG 0 <- [1,534,null,{"value":null}]
[task 2023-08-11T10:20:55.663Z] 10:20:55 INFO - PID 6397 | 1691749255661 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.664Z] 10:20:55 INFO - PID 6397 | 1691749255662 webdriver::server DEBUG -> GET /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window
[task 2023-08-11T10:20:55.664Z] 10:20:55 INFO - PID 6397 | 1691749255663 Marionette DEBUG 0 -> [0,535,"WebDriver:GetWindowHandle",{}]
[task 2023-08-11T10:20:55.665Z] 10:20:55 INFO - PID 6397 | 1691749255664 Marionette DEBUG 0 <- [1,535,null,{"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.666Z] 10:20:55 INFO - PID 6397 | 1691749255665 webdriver::server DEBUG <- 200 OK {"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.667Z] 10:20:55 INFO - PID 6397 | 1691749255666 webdriver::server DEBUG -> GET /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window
[task 2023-08-11T10:20:55.668Z] 10:20:55 INFO - PID 6397 | 1691749255667 Marionette DEBUG 0 -> [0,536,"WebDriver:GetWindowHandle",{}]
[task 2023-08-11T10:20:55.669Z] 10:20:55 INFO - PID 6397 | 1691749255668 Marionette DEBUG 0 <- [1,536,null,{"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.670Z] 10:20:55 INFO - PID 6397 | 1691749255669 webdriver::server DEBUG <- 200 OK {"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.672Z] 10:20:55 INFO - PID 6397 | 1691749255669 webdriver::server DEBUG -> GET /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window/handles
[task 2023-08-11T10:20:55.673Z] 10:20:55 INFO - PID 6397 | 1691749255670 Marionette DEBUG 0 -> [0,537,"WebDriver:GetWindowHandles",{}]
[task 2023-08-11T10:20:55.673Z] 10:20:55 INFO - PID 6397 | 1691749255672 Marionette DEBUG 0 <- [1,537,null,["52783e49-cc6f-42a2-ad00-050ea6101bbb"]]
[task 2023-08-11T10:20:55.674Z] 10:20:55 INFO - PID 6397 | 1691749255673 webdriver::server DEBUG <- 200 OK {"value":["52783e49-cc6f-42a2-ad00-050ea6101bbb"]}
[task 2023-08-11T10:20:55.676Z] 10:20:55 INFO - PID 6397 | 1691749255675 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window {"handle": "52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.677Z] 10:20:55 INFO - PID 6397 | 1691749255676 Marionette DEBUG 0 -> [0,538,"WebDriver:SwitchToWindow",{"handle":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.680Z] 10:20:55 INFO - PID 6397 | 1691749255679 Marionette DEBUG 0 <- [1,538,null,{"value":null}]
[task 2023-08-11T10:20:55.681Z] 10:20:55 INFO - PID 6397 | 1691749255680 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.682Z] 10:20:55 INFO - PID 6397 | 1691749255681 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/alert/dismiss {}
[task 2023-08-11T10:20:55.684Z] 10:20:55 INFO - PID 6397 | 1691749255683 Marionette DEBUG 0 -> [0,539,"WebDriver:DismissAlert",{}]
[task 2023-08-11T10:20:55.687Z] 10:20:55 INFO - PID 6397 | 1691749255685 Marionette DEBUG 0 <- [1,539,{"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:263:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:494:20\n"},null]
[task 2023-08-11T10:20:55.689Z] 10:20:55 INFO - PID 6397 | 1691749255687 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/Remo ... ontent/marionette/server.sys.mjs:263:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:494:20\n"}}
[task 2023-08-11T10:20:55.689Z] 10:20:55 INFO - PID 6397 | 1691749255687 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window {"handle": "52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.692Z] 10:20:55 INFO - PID 6397 | 1691749255691 Marionette DEBUG 0 -> [0,540,"WebDriver:SwitchToWindow",{"handle":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.694Z] 10:20:55 INFO - PID 6397 | 1691749255693 Marionette DEBUG 0 <- [1,540,null,{"value":null}]
[task 2023-08-11T10:20:55.695Z] 10:20:55 INFO - PID 6397 | 1691749255694 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.696Z] 10:20:55 INFO - PID 6397 | 1691749255695 webdriver::server DEBUG -> GET /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window
[task 2023-08-11T10:20:55.698Z] 10:20:55 INFO - PID 6397 | 1691749255697 Marionette DEBUG 0 -> [0,541,"WebDriver:GetWindowHandle",{}]
[task 2023-08-11T10:20:55.699Z] 10:20:55 INFO - PID 6397 | 1691749255697 Marionette DEBUG 0 <- [1,541,null,{"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.700Z] 10:20:55 INFO - PID 6397 | 1691749255698 webdriver::server DEBUG <- 200 OK {"value":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.701Z] 10:20:55 INFO - PID 6397 | 1691749255700 webdriver::server DEBUG -> GET /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window/handles
[task 2023-08-11T10:20:55.703Z] 10:20:55 INFO - PID 6397 | 1691749255701 Marionette DEBUG 0 -> [0,542,"WebDriver:GetWindowHandles",{}]
[task 2023-08-11T10:20:55.705Z] 10:20:55 INFO - PID 6397 | 1691749255702 Marionette DEBUG 0 <- [1,542,null,["52783e49-cc6f-42a2-ad00-050ea6101bbb"]]
[task 2023-08-11T10:20:55.706Z] 10:20:55 INFO - PID 6397 | 1691749255703 webdriver::server DEBUG <- 200 OK {"value":["52783e49-cc6f-42a2-ad00-050ea6101bbb"]}
[task 2023-08-11T10:20:55.707Z] 10:20:55 INFO - PID 6397 | 1691749255704 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window {"handle": "52783e49-cc6f-42a2-ad00-050ea6101bbb"}
[task 2023-08-11T10:20:55.708Z] 10:20:55 INFO - PID 6397 | 1691749255705 Marionette DEBUG 0 -> [0,543,"WebDriver:SwitchToWindow",{"handle":"52783e49-cc6f-42a2-ad00-050ea6101bbb"}]
[task 2023-08-11T10:20:55.709Z] 10:20:55 INFO - PID 6397 | 1691749255707 Marionette DEBUG 0 <- [1,543,null,{"value":null}]
[task 2023-08-11T10:20:55.710Z] 10:20:55 INFO - PID 6397 | 1691749255708 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.711Z] 10:20:55 INFO - PID 6397 | 1691749255708 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/window/rect {"width": 800, "height": 600}
[task 2023-08-11T10:20:55.713Z] 10:20:55 INFO - PID 6397 | 1691749255710 Marionette DEBUG 0 -> [0,544,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2023-08-11T10:20:55.714Z] 10:20:55 INFO - PID 6397 | 1691749255711 Marionette TRACE Requested window geometry matches
[task 2023-08-11T10:20:55.715Z] 10:20:55 INFO - PID 6397 | 1691749255711 Marionette DEBUG 0 <- [1,544,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2023-08-11T10:20:55.717Z] 10:20:55 INFO - PID 6397 | 1691749255712 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2023-08-11T10:20:55.718Z] 10:20:55 INFO - PID 6397 | 1691749255713 webdriver::server DEBUG -> POST /session/e4abeeed-3935-451d-b41b-a73409d08d2c/frame {"id": null}
[task 2023-08-11T10:20:55.719Z] 10:20:55 INFO - PID 6397 | 1691749255714 Marionette DEBUG 0 -> [0,545,"WebDriver:SwitchToFrame",{"id":null}]
[task 2023-08-11T10:20:55.721Z] 10:20:55 INFO - PID 6397 | 1691749255720 Marionette DEBUG 0 <- [1,545,null,{"value":null}]
[task 2023-08-11T10:20:55.723Z] 10:20:55 INFO - PID 6397 | 1691749255721 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2023-08-11T10:20:55.726Z] 10:20:55 INFO - PID 6397 | 1691749255725 webdriver::server DEBUG -> DELETE /session/e4abeeed-3935-451d-b41b-a73409d08d2c
[task 2023-08-11T10:20:55.727Z] 10:20:55 INFO - PID 6397 | 1691749255726 Marionette DEBUG 0 -> [0,546,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2023-08-11T10:20:55.730Z] 10:20:55 INFO - PID 6397 | 1691749255729 Marionette INFO Stopped listening on port 45597
[task 2023-08-11T10:20:55.749Z] 10:20:55 INFO - PID 6397 | 1691749255748 Marionette TRACE [3] MarionetteCommands actor destroyed for window id 4294967297
[task 2023-08-11T10:20:55.756Z] 10:20:55 INFO - PID 6397 | 1691749255754 WebDriver BiDi DEBUG Unregistered session handler: /session/e4abeeed-3935-451d-b41b-a73409d08d2c
[task 2023-08-11T10:20:55.767Z] 10:20:55 INFO - PID 6397 | 1691749255766 RemoteAgent TRACE MessageHandler ROOT for session e4abeeed-3935-451d-b41b-a73409d08d2c is being destroyed
[task 2023-08-11T10:20:55.768Z] 10:20:55 INFO - PID 6397 | 1691749255767 RemoteAgent TRACE Unregistered MessageHandler ROOT for session e4abeeed-3935-451d-b41b-a73409d08d2c
[task 2023-08-11T10:20:56.069Z] 10:20:56 INFO - PID 6397 | 1691749256068 Marionette TRACE Received observer notification quit-application
[task 2023-08-11T10:20:56.090Z] 10:20:56 INFO - PID 6397 | 1691749256089 Marionette TRACE Received observer notification quit-application
[task 2023-08-11T10:20:56.090Z] 10:20:56 INFO - PID 6397 | 1691749256089 RemoteAgent TRACE Received observer notification quit-application
[task 2023-08-11T10:20:56.096Z] 10:20:56 INFO - PID 6397 | 1691749256096 Marionette DEBUG Marionette stopped listening
[task 2023-08-11T10:20:56.098Z] 10:20:56 INFO - PID 6397 | 1691749256097 Marionette DEBUG 0 <- [1,546,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2023-08-11T10:20:56.223Z] 10:20:56 INFO - PID 6397 | 1691749256222 RemoteAgent TRACE MessageHandler WINDOW_GLOBAL for session e4abeeed-3935-451d-b41b-a73409d08d2c is being destroyed
[task 2023-08-11T10:20:56.227Z] 10:20:56 INFO - PID 6397 | 1691749256225 RemoteAgent TRACE Unregistered MessageHandler WINDOW_GLOBAL for session e4abeeed-3935-451d-b41b-a73409d08d2c
[task 2023-08-11T10:20:56.234Z] 10:20:56 INFO - PID 6397 | 1691749256232 RemoteAgent DEBUG Resetting recommended pref browser.contentblocking.features.standard
[task 2023-08-11T10:20:56.234Z] 10:20:56 INFO - PID 6397 | 1691749256233 RemoteAgent DEBUG Resetting recommended pref network.cookie.cookieBehavior
[task 2023-08-11T10:20:56.236Z] 10:20:56 INFO - PID 6397 | 1691749256235 webdriver::server DEBUG Teardown session
[task 2023-08-11T10:20:56.246Z] 10:20:56 INFO - PID 6397 | 1691749256245 Marionette DEBUG Closed connection 0
[task 2023-08-11T10:20:56.395Z] 10:20:56 INFO - PID 6397 | console.error: ({})
[task 2023-08-11T10:20:57.949Z] 10:20:57 INFO - PID 6397 | [Parent 7016, IPC I/O Parent] WARNING: Process 7188 may be hanging at shutdown; will wait for up to 40000ms: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/process_watcher_posix_sigchld.cc:184
[task 2023-08-11T10:21:37.967Z] 10:21:37 INFO - PID 6397 | [Parent 7016, IPC I/O Parent] WARNING: Process 7188 hanging at shutdown; attempting crash report (fatal error).: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/process_watcher_posix_sigchld.cc:207
[task 2023-08-11T10:22:00.973Z] 10:22:00 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/session/unsubscribe/invalid.py | expected OK
[task 2023-08-11T10:22:00.973Z] 10:22:00 INFO - TEST-INFO took 80003ms
[task 2023-08-11T10:22:00.974Z] 10:22:00 INFO - Restarting browser for new test group
[task 2023-08-11T10:22:07.030Z] 10:22:07 INFO - Closing logging queue
[task 2023-08-11T10:22:07.032Z] 10:22:07 INFO - queue closed
[task 2023-08-11T10:22:07.038Z] 10:22:07 INFO - PID 7292 | 1691749327037 geckodriver INFO Listening on 127.0.0.1:56232
[task 2023-08-11T10:22:07.039Z] 10:22:07 INFO - Starting runner
[task 2023-08-11T10:22:07.278Z] 10:22:07 INFO - TEST-START | /webdriver/tests/classic/dismiss_alert/dismiss.py
|
||
Comment 1•1 year ago
|
||
Shutdown hang of Firefox
You need to log in
before you can comment on or make changes to this bug.
Description
•