Closed Bug 1790210 Opened 2 years ago Closed 2 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/navigate.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Platform:
All
Android
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

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

[task 2022-09-10T13:25:11.654Z] 13:25:11     INFO - PID 2448 | 1662816311639	mozdevice	TRACE	execute_host_command: << []
[task 2022-09-10T13:25:11.655Z] 13:25:11     INFO - PID 2448 | 1662816311639	mozdevice	TRACE	execute_host_command: >> "shell:ls /data/local/tmp"
[task 2022-09-10T13:25:11.656Z] 13:25:11     INFO - PID 2448 | 1662816311652	mozdevice	TRACE	execute_host_command: << "test_root\n"
[task 2022-09-10T13:25:11.657Z] 13:25:11     INFO - PID 2448 | 1662816311654	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-09-10T13:25:11.657Z] 13:25:11     INFO - PID 2448 | 1662816311654	mozdevice	TRACE	execute_host_command: << []
[task 2022-09-10T13:25:11.658Z] 13:25:11     INFO - PID 2448 | 1662816311654	mozdevice	TRACE	execute_host_command: >> "shell:am set-debug-app --persistent org.mozilla.geckoview.test_runner"
[task 2022-09-10T13:25:11.861Z] 13:25:11     INFO - PID 2448 | 1662816311860	mozdevice	TRACE	execute_host_command: << ""
[task 2022-09-10T13:25:11.862Z] 13:25:11     INFO - PID 2448 | 1662816311860	geckodriver::android	DEBUG	Launching org.mozilla.geckoview.test_runner/.App
[task 2022-09-10T13:25:11.863Z] 13:25:11     INFO - PID 2448 | 1662816311861	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-09-10T13:25:11.863Z] 13:25:11     INFO - PID 2448 | 1662816311861	mozdevice	TRACE	execute_host_command: << []
[task 2022-09-10T13:25:11.864Z] 13:25:11     INFO - PID 2448 | 1662816311861	mozdevice	TRACE	execute_host_command: >> "shell:am start -W -n org.mozilla.geckoview.test_runner/.App -a android.intent.action.VIEW -d about:blank --es args \"--marionette --profile /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root/org.mozilla.geckoview.test_runner-geckodriver-profile\""
[task 2022-09-10T13:25:12.585Z] 13:25:12     INFO - PID 2448 | 1662816312583	mozdevice	TRACE	execute_host_command: << "Starting: Intent { act=android.intent.action.VIEW dat=about:blank cmp=org.mozilla.geckoview.test_runner/.App (has extras) }\nStatus: ok\nActivity: org.mozilla.geckoview.test_runner/.App\nThisTime: 505\nTotalTime: 505\nWaitTime: 509\nComplete\n"
[task 2022-09-10T13:25:12.586Z] 13:25:12     INFO - PID 2448 | 1662816312583	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2022-09-10T13:25:12.636Z] 13:25:12     INFO - PID 2448 | 1662816312634	geckodriver::marionette	DEBUG	Connection to Marionette established on 127.0.0.1:38515.
[task 2022-09-10T13:25:12.829Z] 13:25:12     INFO - PID 2448 | 1662816312825	webdriver::server	DEBUG	<- 200 OK {"value":{"sessionId":"dd6f5b5f-3daf-40b9-9271-b02e1e41eb67","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"106.0","moz:accessibilityChecks":false,"moz:buildID":"20220910105306","moz:debuggerAddress":"127.0.0.1:9222","moz:geckodriverVersion":"0.31.0","moz:headless":false,"moz:platformVersion":24,"moz:processID":11681,"moz:profile":"/storage/emulated/0/Android/data/org.mozilla.geckoview.test_runner/files/test_root/org.mozilla.geckoview.test_runner-geckodriver-profile","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"pageLoadStrategy":"normal","platformName":"android","proxy":{},"setWindowRect":false,"strictFileInteractability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify","webSocketUrl":"ws://127.0.0.1:9222/session/dd6f5b5f-3daf-40b9-9271-b02e1e41eb67"}}}
[task 2022-09-10T13:26:55.163Z] 13:26:55     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/browsing_context/navigate/navigate.py | expected OK
[task 2022-09-10T13:26:55.163Z] 13:26:55     INFO - TEST-INFO took 105006ms
[task 2022-09-10T13:27:05.225Z] 13:27:05  WARNING - Forcibly terminating runner process
[task 2022-09-10T13:27:05.382Z] 13:27:05     INFO - PID 2747 | 1662816425379	geckodriver	INFO	Listening on 127.0.0.1:39115
[task 2022-09-10T13:27:05.383Z] 13:27:05     INFO - Starting runner
[task 2022-09-10T13:27:05.641Z] 13:27:05     INFO - TEST-START | /webdriver/tests/bidi/browsing_context/navigate/wait.py
[task 2022-09-10T13:27:05.870Z] 13:27:05     INFO - STDOUT: ============================= test session starts ==============================
[task 2022-09-10T13:27:05.871Z] 13:27:05     INFO - STDOUT: platform linux -- Python 3.6.9, pytest-7.0.1, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2022-09-10T13:27:05.872Z] 13:27:05     INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2022-09-10T13:27:05.873Z] 13:27:05     INFO - STDOUT: plugins: asyncio-0.14.0
[task 2022-09-10T13:27:05.874Z] 13:27:05     INFO - STDOUT: collecting ... 
[task 2022-09-10T13:27:05.884Z] 13:27:05     INFO - STDOUT: collected 12 items
[task 2022-09-10T13:27:05.885Z] 13:27:05     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/browsing_context/navigate/wait.py::test_expected_url[none]

Not exactly sure what's going on here. We seem to hang in the WebDriver:NewSession command while waiting for the navigation events. It's a new test on Android as enabled by bug 1506782. Lets observe how often this happens.

Depends on: 1506782
OS: Unspecified → Android
Hardware: Unspecified → All

I(In reply to Intermittent Failures Robot from comment #3)

1 failures in 3023 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

That was wrongly classified and is actually bug 1790325.

Given that this failure didn't occur again lets close this bug as incomplete.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
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.