search

mozilla / geckodriver

WebDriver for Firefox
https://firefox-source-docs.mozilla.org/testing/geckodriver/
Mozilla Public License 2.0
7.03k stars 1.51k forks source link

`geckodriver` `0.33.0` fails to launch using Firefox 121.0 on macOS #2147

Closed shailshouryya closed 6 months ago

shailshouryya commented 6 months ago

System

Testcase

curl -SL https://github.com/mozilla/geckodriver/releases/download/v0.33.0/geckodriver-v0.33.0-macos.tar.gz | tar -xzvf - -C /usr/local/bin/ && chmod +x /usr/local/bin/geckodriver

python3.12 -m pip install selenium==3.141
python3.12
from selenium import webdriver
driver = webdriver.Firefox()

Stacktrace

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/firefox/webdriver.py", line 170, in __init__
    RemoteWebDriver.__init__(
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in __init__
    self.start_session(capabilities, browser_profile)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session
    response = self.execute(Command.NEW_SESSION, parameters)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
    self.error_handler.check_response(response)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.WebDriverException: Message: Process unexpectedly closed with status signal

and geckodriver.log contains

1704258926362   geckodriver INFO    Listening on 127.0.0.1:49990
1704258927382   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1"

Trace-level log

# from line 177 at
# https://searchfox.org/mozilla-central/rev/0f39860036f9b6339e65d485aeb6b6be73d9dbda/testing/geckodriver/doc/TraceLogs.md

from selenium.webdriver import Firefox
from selenium.webdriver.firefox.options import Options

opts = Options()
opts.log.level = "trace"
driver = Firefox(options=opts)

Results in

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/firefox/webdriver.py", line 170, in __init__
    RemoteWebDriver.__init__(
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in __init__
    self.start_session(capabilities, browser_profile)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session
    response = self.execute(Command.NEW_SESSION, parameters)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
    self.error_handler.check_response(response)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.WebDriverException: Message: Process unexpectedly closed with status signal

and geckodriver.log now contains

1704259780816   geckodriver INFO    Listening on 127.0.0.1:50335
1704259780826   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1704259780826   geckodriver::capabilities   DEBUG   Found version 121.0
1704259780833   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/App ... "--marionette" "-foreground" "-no-remote" "-profile" "/var/folders/ch/vskbs73j2l15kc4w2q_74gpc0000gq/T/rust_mozprofileKZrrm6"
1704259780895   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1704259780896   geckodriver::browser    TRACE   Failed to open /var/folders/ch/vskbs73j2l15kc4w2q_74gpc0000gq/T/rust_mozprofileKZrrm6/MarionetteActivePort
1704259780896   geckodriver::marionette TRACE   Retrying in 100ms
1704259781001   geckodriver::browser    DEBUG   Browser process stopped: signal: 9 (SIGKILL)
1704259781002   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}

Additional Notes

I looked at https://github.com/mozilla/geckodriver/issues/2146, which initially looked unrelated, although on closer inspection, my geckodriver.log does have a similar Failed to open ... MarionetteActivePort message (compared to the selenium.common.exceptions.TimeoutException: Message: Failed to read marionette port in that issue):

1704259780896   geckodriver::browser    TRACE   Failed to open /var/folders/ch/vskbs73j2l15kc4w2q_74gpc0000gq/T/rust_mozprofileKZrrm6/MarionetteActivePort

after adding the

opts = Options()
opts.log.level = "trace"
driver = Firefox(options=opts)

for the Trace-level log section

I also looked at https://github.com/mozilla/geckodriver/issues/2144 (which may be related, but that thread seems to be discussing the 4.16.0 and not the 3.141.0 geckodriver client), but that thread also does not address this specific problem.

Also, I tried updating selenium to the latest available release with python3.12 -m pip install -U selenium (to selenium-4.16.0) since I suspected there might be something hard-coded somewhere that is breaking, and sure enough, the selenium-4.16.0 client does not raise any errors.

However, installing Firefox version 120.0.1 from https://support.mozilla.org/en-US/kb/install-older-version-firefox?redirectslug=install-older-version-of-firefox&redirectlocale=en-US (from https://download-installer.cdn.mozilla.net/pub/firefox/releases/120.0.1/mac/en-US/Firefox%20120.0.1.dmg) and then downgrading to the older selenium-3.141.0 client again with

python3.12 -m pip install selenium==3.141
python3.12
from selenium import webdriver
driver = webdriver.Firefox()

also does not result in any errors, so I'm guessing something is hard-coded in the Firefox binary (as opposed something hard-coded in the geckodriver binary), since keeping everything the same and changing just the browser version from Firefox 120.0.1 to 121.0 (the current latest available (stable) release) results in a failure.

This seems a bit odd to me, since I expected the geckodriver binary to raise an exception for old geckodriver clients, and expected the Firefox binary to be oblivious to which geckodriver client is being used, but this does not seem to be the case.

I realize I am using an old geckodriver client, but I still think this might be a valid problem since it seems like the Firefox binary (and not the geckodriver binary) seems to be checking the geckodriver client, which seems... strange. One suggestion I have is to make the geckodriver binary - as opposed to the Firefox binary - the geckodriver client "checker," as having the Firefox binary check the geckodriver client seems to be leaking/coupling responsibility with an independent (I think?) piece of software. By making the geckodriver binary the sole "checker" of the clients, we can maintain tighter responsibilty and also inform users of deprecations/removals in one place (the geckodriver release page), as opposed to users having to also check the Firefox release notes (although https://www.mozilla.org/en-US/firefox/121.0/releasenotes/ also does not mention any geckodriver client deprecation/removals). My diagnosis might not be correct, though, and in that case, ignore this last paragraph! 😅

whimboo commented 6 months ago

Can you please check the trace log output for the exact Firefox binary that gets started? Is it firefox-bin?

Also we have a nightly build of the upcoming geckodriver 0.34.0. Would you mind checking if that version fixes your problem?

Thanks a lot.

shailshouryya commented 6 months ago

Can you please check the trace log output for the exact Firefox binary that gets started? Is it firefox-bin?

How do I check this? If this is similar to this comment and is referring to how/where I downloaded the Firefox binary, I downloaded Firefox 121.0.dmg from https://www.mozilla.org/en-US/firefox/download/thanks/ (so I did not download Firefox through homebrew or any other tool) and Firefox is installed at /Applications/Firefox.app/Contents/MacOS/firefox. Here is the output from launching the binary directly in Finder:

/Applications/Firefox.app/Contents/MacOS/firefox ; exit;
2024-01-02 23:45:55.685 plugin-container[5794:168737] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-02 23:45:55.686 plugin-container[5794:168737] nil host used in call to allowsAnyHTTPSCertificateForHost:
2024-01-02 23:45:55.690 plugin-container[5794:168737] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-02 23:45:55.690 plugin-container[5794:168737] nil host used in call to allowsAnyHTTPSCertificateForHost:
2024-01-02 23:45:55.690 plugin-container[5794:168740] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-02 23:45:55.690 plugin-container[5794:168740] nil host used in call to allowsAnyHTTPSCertificateForHost:
# switches to UTC time here 🤔
2024-01-03 07:45:58.366 plugin-container[5801:168978] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-03 07:45:58.366 plugin-container[5801:168978] nil host used in call to allowsAnyHTTPSCertificateForHost:
2024-01-03 07:45:58.370 plugin-container[5801:168978] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-03 07:45:58.370 plugin-container[5801:168978] nil host used in call to allowsAnyHTTPSCertificateForHost:
2024-01-03 07:45:58.370 plugin-container[5801:168979] nil host used in call to allowsSpecificHTTPSCertificateForHost
2024-01-03 07:45:58.371 plugin-container[5801:168979] nil host used in call to allowsAnyHTTPSCertificateForHost:

I did post the output from the geckodriver.log file after running

# from line 177 at
# https://searchfox.org/mozilla-central/rev/0f39860036f9b6339e65d485aeb6b6be73d9dbda/testing/geckodriver/doc/TraceLogs.md

from selenium.webdriver import Firefox
from selenium.webdriver.firefox.options import Options

opts = Options()
opts.log.level = "trace"
driver = Firefox(options=opts)

in my original post above, but reran and including again below for convenience (neither the original run nor this run includes firefox-bin, though):

from selenium.webdriver import Firefox
from selenium.webdriver.firefox.options import Options

opts = Options()
opts.log.level = "trace"
driver = Firefox(options=opts)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/firefox/webdriver.py", line 170, in __init__
    RemoteWebDriver.__init__(
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in __init__
    self.start_session(capabilities, browser_profile)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session
    response = self.execute(Command.NEW_SESSION, parameters)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
    self.error_handler.check_response(response)
  File "/Library/Frameworks/Python.framework/Versions/3.12/lib/python3.12/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.WebDriverException: Message: Process unexpectedly closed with status signal

the geckodriver.log output:

1704268311499   geckodriver INFO    Listening on 127.0.0.1:62111
1704268312354   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1704268312356   geckodriver::capabilities   DEBUG   Found version 121.0
1704268312367   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/App ... "--marionette" "-foreground" "-no-remote" "-profile" "/var/folders/ch/vskbs73j2l15kc4w2q_74gpc0000gq/T/rust_mozprofile2sPjdJ"
1704268312434   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1704268312434   geckodriver::browser    TRACE   Failed to open /var/folders/ch/vskbs73j2l15kc4w2q_74gpc0000gq/T/rust_mozprofile2sPjdJ/MarionetteActivePort
1704268312434   geckodriver::marionette TRACE   Retrying in 100ms
1704268312535   geckodriver::browser    DEBUG   Browser process stopped: signal: 9 (SIGKILL)
1704268312536   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}

In my case, I think the Firefox binary isn't even getting launched (or loaded) since (I think) geckodriver crashes before getting that far. FWIW, I also tested this with 0.32.0, 0.32.1, and 0.32.2 in addition to 0.33.0 (from https://github.com/mozilla/geckodriver/releases), and none of the other geckodriver binaries worked either.

If this is not what you meant when you said

trace log output for the exact Firefox binary that gets started

can you clarify how to check the "trace log output"?




Also we have a nightly build of the upcoming geckodriver 0.34.0. Would you mind checking if that version fixes your problem?

Yes, the (current) nightly build works! Here's a quick reproduction:

curl -SL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/D2C3KWToSwqhf3naO3C9AA/runs/0/artifacts/public/build/geckodriver.tar.gz | tar -xzvf - -C /usr/local/bin/ && chmod +x /usr/local/bin/geckodriver

python3.12 -m pip install selenium==3.141
python3.12

# alternatively, to install the latest selenium client for python3, run
# python3.12 -m pip -U install selenium
# or
# python3 -m pip -U install selenium
# python3

and then

# this works
from selenium import webdriver
driver = webdriver.Firefox()
# this also works!
from selenium.webdriver import Firefox
from selenium.webdriver.firefox.options import Options

opts = Options()
opts.log.level = "trace"
driver = Firefox(options=opts)

Here is the geckodriver information after running geckodriver -V:

geckodriver 0.34.0 (c44f0d09630a 2024-01-02 15:36 +0000)

The source code of this program is available from
testing/geckodriver in https://hg.mozilla.org/mozilla-central.

This program is subject to the terms of the Mozilla Public License 2.0.
You can obtain a copy of the license at https://mozilla.org/MPL/2.0/.

So I suppose this is a problem with geckodriver releases 0.32.0, 0.32.1, 0.32.2, and 0.33.0 (and possibly earlier versions), but whatever is in the current nightly build mitigates this (and apparently #2144 as well). Out of curiosity, what was the change that fixed both this and #2144?




UPDATE I looked through https://github.com/mozilla/geckodriver/pull/2149/files, and expected something under the `src` file changes to have the fix (particularly in `src/marionette.rs` or `src/main.rs`), but did not see anything immediately obvious - are there other changes from elsewhere that affect the final `geckodriver` binary (https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/D2C3KWToSwqhf3naO3C9AA/runs/0/artifacts/public/build/geckodriver.tar.gz)? I'm not familiar with the changes though, so it's possible I read the fix and didn't realize it. 😅
whimboo commented 6 months ago

Thanks for checking. The problem with the trace log output is that it is truncated "/App ... "--marionette" "-foreground" and as such we do not see the exact binary that gets launched. But given that it works with the new geckodriver binary we can safely mark this issue as dupe of #2144.