Bug 1755312 Comment 0 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Original comment by
on 
There is a regression from bug 1723202 which causes geckodriver to not connect to Marionette if an old and outdated MarionetteActivePort file is found in the profile:

https://treeherder.mozilla.org/logviewer?job_id=367772032&repo=autoland&lineNumber=3137-3157

```
[task 2022-02-14T06:18:08.885Z] 06:18:08     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/errors/errors.py::test_unknown_command[invalid module] 
[task 2022-02-14T06:18:08.889Z] 06:18:08     INFO - PID 7904 | 1644819488887	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner"], "binary": "Z:\\task_164481859927852\\build\\application\\firefox\\firefox.exe"}, "webSocketUrl": true}}}
[task 2022-02-14T06:18:08.890Z] 06:18:08     INFO - PID 7904 | 1644819488888	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2022-02-14T06:18:08.890Z] 06:18:08     INFO - PID 7904 | 1644819488889	geckodriver::capabilities	DEBUG	Found version 99.0a1
[task 2022-02-14T06:18:08.891Z] 06:18:08     INFO - PID 7904 | 1644819488889	geckodriver::browser	DEBUG	Backing up prefs to "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner\\user.geckodriver_backup_1"
[task 2022-02-14T06:18:08.904Z] 06:18:08     INFO - PID 7904 | 1644819488903	mozrunner::runner	INFO	Running command: "Z:\\task_164481859927852\\build\\application\\firefox\\firefox.exe" "--marionette" "--profile" "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner" "--remote-debugging-port" "9222" "-no-remote"
[task 2022-02-14T06:18:08.906Z] 06:18:08     INFO - PID 7904 | 1644819488905	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2022-02-14T06:18:08.907Z] 06:18:08     INFO - PID 7904 | Read port: 50073
[task 2022-02-14T06:18:08.967Z] 06:18:08     INFO - PID 7904 | *** You are running in headless mode.
[task 2022-02-14T06:18:09.095Z] 06:18:09     INFO - PID 7904 | 1644819489107	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2022-02-14T06:18:09.109Z] 06:18:09     INFO - PID 7904 | 1644819489107	RemoteAgent	DEBUG	CDP enabled
[task 2022-02-14T06:18:09.110Z] 06:18:09     INFO - PID 7904 | 1644819489107	Marionette	INFO	Marionette enabled
[task 2022-02-14T06:18:09.405Z] 06:18:09     INFO - PID 7904 | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2022-02-14T06:18:09.892Z] 06:18:09     INFO - PID 7904 | 1644819489904	RemoteAgent	TRACE	Received observer notification remote-startup-requested
[task 2022-02-14T06:18:09.908Z] 06:18:09     INFO - PID 7904 | 1644819489911	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2022-02-14T06:18:09.912Z] 06:18:09     INFO - PID 7904 | 1644819489911	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2022-02-14T06:18:09.913Z] 06:18:09     INFO - PID 7904 | DevTools listening on ws://localhost:9222/devtools/browser/fed4cf86-5ede-41a3-8dd6-41a3b05a1490
[task 2022-02-14T06:18:09.916Z] 06:18:09     INFO - PID 7904 | WebDriver BiDi listening on ws://localhost:9222
[task 2022-02-14T06:18:09.992Z] 06:18:09     INFO - PID 7904 | 1644819489995	Marionette	TRACE	All scripts recorded.
[task 2022-02-14T06:18:09.997Z] 06:18:09     INFO - PID 7904 | 1644819489996	Marionette	INFO	Listening on port 50316
[task 2022-02-14T06:18:09.997Z] 06:18:09     INFO - PID 7904 | 1644819489997	Marionette	DEBUG	Marionette is listening
[task 2022-02-14T06:18:10.933Z] 06:18:10     INFO - PID 7904 | 1644819490932	geckodriver::marionette	TRACE	Retrying in 100ms
[..]
[task 2022-02-14T06:18:36.482Z] 06:18:36     INFO - PID 7904 | 1644819516482	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-02-14T06:18:38.527Z] 06:18:38     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/errors/errors.py | expected OK
```

As the log above shows we read the port once from the file and keep it set while trying to connect. But the file will be overwritten with the updated port by Marionette once it's listening. And this port is missed.
Revision 1 by
on 
There is a regression from bug 1421766 which causes geckodriver to not connect to Marionette if an old and outdated MarionetteActivePort file is found in the profile:

https://treeherder.mozilla.org/logviewer?job_id=367772032&repo=autoland&lineNumber=3137-3157

```
[task 2022-02-14T06:18:08.885Z] 06:18:08     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/bidi/errors/errors.py::test_unknown_command[invalid module] 
[task 2022-02-14T06:18:08.889Z] 06:18:08     INFO - PID 7904 | 1644819488887	webdriver::server	DEBUG	-> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner"], "binary": "Z:\\task_164481859927852\\build\\application\\firefox\\firefox.exe"}, "webSocketUrl": true}}}
[task 2022-02-14T06:18:08.890Z] 06:18:08     INFO - PID 7904 | 1644819488888	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
[task 2022-02-14T06:18:08.890Z] 06:18:08     INFO - PID 7904 | 1644819488889	geckodriver::capabilities	DEBUG	Found version 99.0a1
[task 2022-02-14T06:18:08.891Z] 06:18:08     INFO - PID 7904 | 1644819488889	geckodriver::browser	DEBUG	Backing up prefs to "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner\\user.geckodriver_backup_1"
[task 2022-02-14T06:18:08.904Z] 06:18:08     INFO - PID 7904 | 1644819488903	mozrunner::runner	INFO	Running command: "Z:\\task_164481859927852\\build\\application\\firefox\\firefox.exe" "--marionette" "--profile" "C:\\Users\\task_164481859927852\\AppData\\Local\\Temp\\tmp10k83yzp.mozrunner" "--remote-debugging-port" "9222" "-no-remote"
[task 2022-02-14T06:18:08.906Z] 06:18:08     INFO - PID 7904 | 1644819488905	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
[task 2022-02-14T06:18:08.907Z] 06:18:08     INFO - PID 7904 | Read port: 50073
[task 2022-02-14T06:18:08.967Z] 06:18:08     INFO - PID 7904 | *** You are running in headless mode.
[task 2022-02-14T06:18:09.095Z] 06:18:09     INFO - PID 7904 | 1644819489107	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2022-02-14T06:18:09.109Z] 06:18:09     INFO - PID 7904 | 1644819489107	RemoteAgent	DEBUG	CDP enabled
[task 2022-02-14T06:18:09.110Z] 06:18:09     INFO - PID 7904 | 1644819489107	Marionette	INFO	Marionette enabled
[task 2022-02-14T06:18:09.405Z] 06:18:09     INFO - PID 7904 | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2022-02-14T06:18:09.892Z] 06:18:09     INFO - PID 7904 | 1644819489904	RemoteAgent	TRACE	Received observer notification remote-startup-requested
[task 2022-02-14T06:18:09.908Z] 06:18:09     INFO - PID 7904 | 1644819489911	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2022-02-14T06:18:09.912Z] 06:18:09     INFO - PID 7904 | 1644819489911	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2022-02-14T06:18:09.913Z] 06:18:09     INFO - PID 7904 | DevTools listening on ws://localhost:9222/devtools/browser/fed4cf86-5ede-41a3-8dd6-41a3b05a1490
[task 2022-02-14T06:18:09.916Z] 06:18:09     INFO - PID 7904 | WebDriver BiDi listening on ws://localhost:9222
[task 2022-02-14T06:18:09.992Z] 06:18:09     INFO - PID 7904 | 1644819489995	Marionette	TRACE	All scripts recorded.
[task 2022-02-14T06:18:09.997Z] 06:18:09     INFO - PID 7904 | 1644819489996	Marionette	INFO	Listening on port 50316
[task 2022-02-14T06:18:09.997Z] 06:18:09     INFO - PID 7904 | 1644819489997	Marionette	DEBUG	Marionette is listening
[task 2022-02-14T06:18:10.933Z] 06:18:10     INFO - PID 7904 | 1644819490932	geckodriver::marionette	TRACE	Retrying in 100ms
[..]
[task 2022-02-14T06:18:36.482Z] 06:18:36     INFO - PID 7904 | 1644819516482	geckodriver::marionette	TRACE	Retrying in 100ms
[task 2022-02-14T06:18:38.527Z] 06:18:38     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/errors/errors.py | expected OK
```

As the log above shows we read the port once from the file and keep it set while trying to connect. But the file will be overwritten with the updated port by Marionette once it's listening. And this port is missed.

Back to Bug 1755312 Comment 0