Closed Bug 1769444 Opened 2 years ago Closed 2 years ago

Intermittent [tier2] ASAN TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1760291

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

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

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

task 2022-05-14T10:52:59.840Z] 10:52:59     INFO - TEST-START | /webdriver/tests/bidi/browsing_context/navigate/wait.py
[task 2022-05-14T10:52:59.891Z] 10:52:59     INFO - STDOUT: ============================= test session starts ==============================
[task 2022-05-14T10:52:59.892Z] 10:52:59     INFO - STDOUT: platform linux -- Python 3.6.9, pytest-6.1.1, py-1.5.2, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2022-05-14T10:52:59.894Z] 10:52:59     INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2022-05-14T10:52:59.895Z] 10:52:59     INFO - STDOUT: plugins: asyncio-0.14.0
[task 2022-05-14T10:52:59.895Z] 10:52:59     INFO - STDOUT: collecting ... 
[task 2022-05-14T10:52:59.906Z] 10:52:59     INFO - STDOUT: collected 12 items
[task 2022-05-14T10:52:59.907Z] 10:52:59     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/browsing_context/navigate/wait.py::test_expected_url[none] 
[task 2022-05-14T10:52:59.908Z] 10:52:59     INFO - PID 1694 | 1652525579907	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/tmp/tmpthowfylp.mozrunner"], "binary": "/builds/worker/workspace/build/application/firefox/firefox"}, "webSocketUrl": true}}}
[task 2022-05-14T10:52:59.909Z] 10:52:59     INFO - PID 1694 | 1652525579907	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2022-05-14T10:52:59.909Z] 10:52:59     INFO - PID 1694 | 1652525579907	geckodriver::capabilities	DEBUG	Found version 102.0a1
[task 2022-05-14T10:52:59.910Z] 10:52:59     INFO - PID 1694 | 1652525579908	geckodriver::browser	DEBUG	Backing up prefs to "/tmp/tmpthowfylp.mozrunner/user.geckodriver_backup"
[task 2022-05-14T10:52:59.915Z] 10:52:59     INFO - PID 1694 | 1652525579914	mozrunner::runner	INFO	Running command: "/builds/worker/workspace/build/application/firefox/firefox" "--marionette" "--profile" "/tmp/tmpthowfylp.mozrunner" "--remote-debugging-port" "9222" "--remote-allow-hosts" "localhost" "-no-remote"
[task 2022-05-14T10:52:59.915Z] 10:52:59     INFO - PID 1694 | 1652525579914	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2022-05-14T10:52:59.916Z] 10:52:59     INFO - PID 1694 | 1652525579914	geckodriver::browser	TRACE	Failed to open /tmp/tmpthowfylp.mozrunner/MarionetteActivePort
[task 2022-05-14T10:52:59.916Z] 10:52:59     INFO - PID 1694 | 1652525579914	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-05-14T10:52:59.980Z] 10:52:59     INFO - PID 1694 | *** You are running in headless mode.

[task 2022-05-14T10:53:03.854Z] 10:53:03     INFO - PID 1694 | 1652525583853	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 45
[task 2022-05-14T10:53:03.873Z] 10:53:03     INFO - PID 1694 | 1652525583871	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session 812e316f-0fc6-41d3-87d0-4283c6bb97b7 is being destroyed
[task 2022-05-14T10:53:03.874Z] 10:53:03     INFO - PID 1694 | 1652525583872	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session 812e316f-0fc6-41d3-87d0-4283c6bb97b7
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 | Suppressions used:
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 |   count      bytes template
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 |      12        384 nsComponentManagerImpl
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 |       2        288 libfontconfig.so
[task 2022-05-14T10:53:04.228Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.296Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.297Z] 10:53:04     INFO - PID 1694 | Suppressions used:
[task 2022-05-14T10:53:04.298Z] 10:53:04     INFO - PID 1694 |   count      bytes template
[task 2022-05-14T10:53:04.299Z] 10:53:04     INFO - PID 1694 |      12        384 nsComponentManagerImpl
[task 2022-05-14T10:53:04.299Z] 10:53:04     INFO - PID 1694 |       2        288 libfontconfig.so
[task 2022-05-14T10:53:04.299Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.672Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.673Z] 10:53:04     INFO - PID 1694 | Suppressions used:
[task 2022-05-14T10:53:04.673Z] 10:53:04     INFO - PID 1694 |   count      bytes template
[task 2022-05-14T10:53:04.673Z] 10:53:04     INFO - PID 1694 |      12        384 nsComponentManagerImpl
[task 2022-05-14T10:53:04.673Z] 10:53:04     INFO - PID 1694 |       2        288 libfontconfig.so
[task 2022-05-14T10:53:04.673Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.874Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:53:04.875Z] 10:53:04     INFO - PID 1694 | Suppressions used:
[task 2022-05-14T10:53:04.875Z] 10:53:04     INFO - PID 1694 |   count      bytes template
[task 2022-05-14T10:53:04.876Z] 10:53:04     INFO - PID 1694 |      12        384 nsComponentManagerImpl
[task 2022-05-14T10:53:04.876Z] 10:53:04     INFO - PID 1694 |       2        288 libfontconfig.so
[task 2022-05-14T10:53:04.876Z] 10:53:04     INFO - PID 1694 | -----------------------------------------------------
[task 2022-05-14T10:54:19.842Z] 10:54:19     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK
[task 2022-05-14T10:54:19.842Z] 10:54:19     INFO - TEST-INFO took 80002ms
[task 2022-05-14T10:54:29.888Z] 10:54:29  WARNING - Forcibly terminating runner process
[task 2022-05-14T10:54:29.899Z] 10:54:29     INFO - PID 5858 | 1652525669897	geckodriver	INFO	Listening on 127.0.0.1:46924
[task 2022-05-14T10:54:29.900Z] 10:54:29     INFO - Starting runner
Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK → Intermittent [tier2] TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK

Timeout when loading a page as served via wptserve:

[task 2022-05-14T10:53:03.649Z] 10:53:03     INFO - PID 1694 | 1652525583644	WebDriver BiDi	DEBUG	812e316f-0fc6-41d3-87d0-4283c6bb97b7 -> {"id":8,"method":"browsingContext.navigate","params":{"context":"41bb7cb6-618e-4032-9bfc-dd3bdb8980b9","url":"http://web-plat ... 21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Efoo%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8","wait":"complete"}}
[task 2022-05-14T10:53:03.649Z] 10:53:03     INFO - PID 1694 | 1652525583644	RemoteAgent	TRACE	Received command browsingContext.navigate for destination ROOT
[task 2022-05-14T10:53:03.649Z] 10:53:03     INFO - PID 1694 | 1652525583645	RemoteAgent	TRACE	Received command browsingContext._getBaseURL for destination WINDOW_GLOBAL
[task 2022-05-14T10:53:03.812Z] 10:53:03     INFO - PID 1694 | 1652525583810	RemoteAgent	TRACE	Created MessageHandler WINDOW_GLOBAL for session 812e316f-0fc6-41d3-87d0-4283c6bb97b7
[task 2022-05-14T10:53:03.812Z] 10:53:03     INFO - PID 1694 | 1652525583810	RemoteAgent	TRACE	Received command browsingContext._getBaseURL for destination WINDOW_GLOBAL
[task 2022-05-14T10:53:03.838Z] 10:53:03     INFO - PID 1694 | 1652525583830	RemoteAgent	TRACE	Module windowglobal/browsingContext.jsm found for WINDOW_GLOBAL
[task 2022-05-14T10:53:03.854Z] 10:53:03     INFO - PID 1694 | 1652525583853	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 45
[task 2022-05-14T10:53:03.873Z] 10:53:03     INFO - PID 1694 | 1652525583871	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session 812e316f-0fc6-41d3-87d0-4283c6bb97b7 is being destroyed
[task 2022-05-14T10:53:03.874Z] 10:53:03     INFO - PID 1694 | 1652525583872	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session 812e316f-0fc6-41d3-87d0-4283c6bb97b7
[task 2022-05-14T10:54:19.842Z] 10:54:19     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK
Summary: Intermittent [tier2] TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK → Intermittent [tier2] ASAN TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/wait.py | expected OK

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

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Resolution: INCOMPLETE → DUPLICATE
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.