Closed Bug 1794578 Opened 3 years ago Closed 3 years ago

Intermittent [Tier 2] TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/create/type.py | expected OK

Categories

(Remote Protocol :: WebDriver BiDi, defect, P5)

Product:
Remote Protocol
Component:
WebDriver BiDi
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered])

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

INFO - TEST-START | /webdriver/tests/bidi/browsing_context/create/type.py
[task 2022-10-11T10:30:47.613Z] 10:30:47     INFO - STDOUT: ============================== 7 passed in 6.08s ===============================
[task 2022-10-11T10:30:47.667Z] 10:30:47     INFO - STDOUT: ============================= test session starts ==============================
[task 2022-10-11T10:30:47.669Z] 10:30:47     INFO - STDOUT: platform linux -- Python 3.6.9, pytest-7.0.1, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2022-10-11T10:30:47.670Z] 10:30:47     INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2022-10-11T10:30:47.671Z] 10:30:47     INFO - STDOUT: plugins: asyncio-0.14.0
[task 2022-10-11T10:30:47.671Z] 10:30:47     INFO - STDOUT: collecting ... 
[task 2022-10-11T10:30:47.678Z] 10:30:47     INFO - STDOUT: collected 2 items
[task 2022-10-11T10:30:47.682Z] 10:30:47     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/browsing_context/create/type.py::test_type[tab] 
[task 2022-10-11T10:30:47.683Z] 10:30:47     INFO - PID 1277 | 1665484247679	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/tmp/tmpvxb3knl3.mozrunner"], "binary": "/builds/worker/workspace/build/application/firefox/firefox"}, "webSocketUrl": true}}}
[task 2022-10-11T10:30:47.683Z] 10:30:47     INFO - PID 1277 | 1665484247679	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2022-10-11T10:30:47.684Z] 10:30:47     INFO - PID 1277 | 1665484247679	geckodriver::capabilities	DEBUG	Found version 107.0a1
[task 2022-10-11T10:30:47.685Z] 10:30:47     INFO - PID 1277 | 1665484247680	geckodriver::browser	DEBUG	Backing up prefs to "/tmp/tmpvxb3knl3.mozrunner/user.geckodriver_backup"
[task 2022-10-11T10:30:47.687Z] 10:30:47     INFO - PID 1277 | 1665484247685	mozrunner::runner	INFO	Running command: "/builds/worker/workspace/build/application/firefox/firefox" "--marionette" "--profile" "/tmp/tmpvxb3knl3.mozrunner" "--remote-debugging-port" "9222" "--remote-allow-hosts" "localhost" "-no-remote"
[task 2022-10-11T10:30:47.687Z] 10:30:47     INFO - PID 1277 | 1665484247686	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2022-10-11T10:30:47.687Z] 10:30:47     INFO - PID 1277 | 1665484247686	geckodriver::browser	TRACE	Failed to open /tmp/tmpvxb3knl3.mozrunner/MarionetteActivePort
[task 2022-10-11T10:30:47.687Z] 10:30:47     INFO - PID 1277 | 1665484247686	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-10-11T10:30:47.745Z] 10:30:47     INFO - PID 1277 | [CodeCoverage] Setting handlers for process 2395.
[task 2022-10-11T10:30:47.746Z] 10:30:47     INFO - PID 1277 | *** You are running in headless mode.
[task 2022-10-11T10:30:47.787Z] 10:30:47     INFO - PID 1277 | 1665484247786	geckodriver::browser	TRACE	Failed to open /tmp/tmpvxb3knl3.mozrunner/MarionetteActivePort
[task 2022-10-11T10:30:47.788Z] 10:30:47     INFO - PID 1277 | 1665484247786	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-10-11T10:30:47.888Z] 10:30:47     INFO - PID 1277 | 1665484247886	geckodriver::browser	TRACE	Failed to open /tmp/tmpvxb3knl3.mozrunner/MarionetteActivePort
[task 2022-10-11T10:30:47.888Z] 10:30:47     INFO - PID 1277 | 1665484247886	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-10-11T10:30:47.974Z] 10:30:47     INFO - PID 1277 | 1665484247972	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2022-10-11T10:30:47.975Z] 10:30:47     INFO - PID 1277 | 1665484247973	RemoteAgent	DEBUG	CDP enabled
[task 2022-10-11T10:30:47.976Z] 10:30:47     INFO - PID 1277 | 1665484247973	Marionette	INFO	Marionette enabled
[task 2022-10-11T10:30:47.977Z] 10:30:47     INFO - PID 1277 | 1665484247975	Marionette	TRACE	Received observer notification final-ui-startup
[task 2022-10-11T10:30:47.977Z] 10:30:47     INFO - PID 1277 | 1665484247976	Marionette	INFO	Listening on port 33619
[task 2022-10-11T10:30:47.978Z] 10:30:47     INFO - PID 1277 | 1665484247976	Marionette	DEBUG	Marionette is listening
[task 2022-10-11T10:30:47.979Z] 10:30:47     INFO - PID 1277 | 1665484247977	RemoteAgent	TRACE	Received observer notification final-ui-startup
[task 2022-10-11T10:30:47.987Z] 10:30:47     INFO - PID 1277 | Read port: 33619
[task 2022-10-11T10:30:48.022Z] 10:30:48     INFO - PID 1277 | 1665484248021	RemoteAgent	TRACE	Available local IP addresses: 127.0.0.1, [::1]
[task 2022-10-11T10:30:48.026Z] 10:30:48     INFO - PID 1277 | WebDriver BiDi listening on ws://127.0.0.1:9222
INFO - PID 1277 | 1665484248026	CDP	DEBUG	Waiting for initial application window
[task 2022-10-11T10:30:48.032Z] 10:30:48     INFO - PID 1277 | 1665484248031	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:47454
[task 2022-10-11T10:30:48.040Z] 10:30:48     INFO - PID 1277 | 1665484248035	geckodriver::marionette	DEBUG	Connection to Marionette established on 127.0.0.1:33619.
[task 2022-10-11T10:30:48.054Z] 10:30:48     INFO - PID 1277 | 1665484248052	Marionette	DEBUG	0 -> [0,1,"WebDriver:NewSession",{"webSocketUrl":true}]
[task 2022-10-11T10:30:48.057Z] 10:30:48     INFO - PID 1277 | 1665484248056	WebDriver BiDi	DEBUG	Waiting for initial application window
[task 2022-10-11T10:30:48.576Z] 10:30:48     INFO - PID 1277 | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2022-10-11T10:30:49.096Z] 10:30:49     INFO - PID 1277 | [CodeCoverage] Setting handlers for process 2455.
[task 2022-10-11T10:30:49.512Z] 10:30:49     INFO - PID 1277 | 1665484249510	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2022-10-11T10:30:49.512Z] 10:30:49     INFO - PID 1277 | 1665484249510	RemoteAgent	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2022-10-11T10:30:49.518Z] 10:30:49     INFO - PID 1277 | 1665484249516	WebDriver BiDi	DEBUG	Registered session handler: /session/58cd7046-148d-4dc5-bfef-599eedd52c54
[task 2022-10-11T10:30:49.518Z] 10:30:49     INFO - PID 1277 | 1665484249516	Marionette	DEBUG	Waiting for initial application window
[task 2022-10-11T10:30:49.521Z] 10:30:49     INFO - PID 1277 | DevTools listening on ws://127.0.0.1:9222/devtools/browser/54f1be44-a814-4d0f-bdda-432f6f7f5c32
[task 2022-10-11T10:30:49.525Z] 10:30:49     INFO - PID 1277 | 1665484249524	RemoteAgent	TRACE	[3] ProgressListener Check loading state: isStart=true isStop=false
[task 2022-10-11T10:30:49.525Z] 10:30:49     INFO - PID 1277 | 1665484249524	RemoteAgent	TRACE	[3] ProgressListener state=start: about:blank
[task 2022-10-11T10:30:49.572Z] 10:30:49     INFO - PID 1277 | [CodeCoverage] Setting handlers for process 2467.
[task 2022-10-11T10:31:42.618Z] 10:31:42     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/create/type.py | expected OK
[task 2022-10-11T10:31:42.618Z] 10:31:42     INFO - TEST-INFO took 55003ms
[task 2022-10-11T10:31:42.805Z] 10:31:42     INFO - Closing logging queue
[task 2022-10-11T10:31:42.806Z] 10:31:42     INFO - queue closed
[task 2022-10-11T10:31:42.813Z] 10:31:42     INFO - PID 2536 | 1665484302812	geckodriver	INFO	Listening on 127.0.0.1:49658
[task 2022-10-11T10:31:42.814Z] 10:31:42     INFO - Starting runner
[task 2022-10-11T10:31:43.053Z] 10:31:43     INFO - TEST-START | /webdriver/tests/bidi/browsing_context/get_tree/frames.py

It looks like that about:blank never stopped loading. Lets observe how often this test fails.

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

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.