Geckodriver can't start Firefox 121 on Mac when `Contents/MacOS/firefox-bin` is used

soulgalore commented 6 months ago

System

Version: 0.33.0
Platform: Mac OS 14.2
Firefox: 121.0
Selenium: 4.16.0

This happens both on Mac M1 and AMD. This seems to work on Ubuntu where I have 121 up and running.

Testcase

browsertime -b firefox https://www.wikikepdia.org

Stacktrace

[2023-12-20 05:52:26] INFO: firefox failed to start, trying 0 more time(s): Process unexpectedly closed with status signal

Geckodriver log:

1703046910610   geckodriver INFO    Listening on 127.0.0.1:52626
1703046910622   webdriver::server   DEBUG   -> GET /status 
1703046910622   webdriver::server   DEBUG   <- 200 OK {"value":{"message":"","ready":true}}
1703046910641   webdriver::server   DEBUG   -> POST /session {"capabilities":{"firstMatch":[{}],"alwaysMatch":{"browserName":"firefox","pageLoadStrategy":"none","moz:fir ... ry":"/Applications/Firefox.app/Contents/MacOS/firefox-bin","args":["-no-remote","-devtools"],"env":{}},"webSocketUrl":true}}}
1703046910643   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1703046910643   geckodriver::capabilities   DEBUG   Found version 121.0
1703046910644   geckodriver::capabilities   DEBUG   Creating profile directory tree /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/chrome/
1703046910644   geckodriver::capabilities   DEBUG   Creating profile directory tree /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/extensions/
1703046910644   geckodriver::capabilities   DEBUG   Extracting profile to /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/extensions/browsertime-extension@sitespeed.io.xpi
1703046910644   geckodriver::capabilities   DEBUG   Extracting profile to /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/extensions/harexporttrigger@getfirebug.com.xpi
1703046910644   geckodriver::capabilities   DEBUG   Extracting profile to /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/chrome/userChrome.css
1703046910644   geckodriver::capabilities   DEBUG   Extracting profile to /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/cert9.db
1703046910645   geckodriver::capabilities   DEBUG   Extracting profile to /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/key4.db
1703046910651   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/App ... te-allow-hosts" "localhost" "-foreground" "-profile" "/var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE"
1703046910656   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1703046910656   geckodriver::browser    TRACE   Failed to open /var/folders/jx/m9wvcdl12kx2dt9dznxjt3mr0000gn/T/rust_mozprofileWWf4HE/MarionetteActivePort
1703046910656   geckodriver::marionette TRACE   Retrying in 100ms
1703046910761   geckodriver::browser    DEBUG   Browser process stopped: signal: 9 (SIGKILL)
1703046910762   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}

See https://github.com/sitespeedio/browsertime/issues/2041

whimboo commented 6 months ago

Thanks @soulgalore. Would you mind running again with the trace logs enabled? I do not see any output from Firefox in the above pasted log. It's all only from geckodriver.

I can see that you are using a special profile. Does it also happen with a default one as created by geckodriver?

soulgalore commented 6 months ago

I tried this: ./geckodriver --log trace and then in another tab:

 curl -H 'Content-Type: application/json' -d '{"capabilities": {"alwaysMatch": {"acceptInsecureCerts": true}}}' http://localhost:4444/session

{"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}

And the log from Geckodriver:

1703059699623   webdriver::server   DEBUG   -> POST /session {"capabilities": {"alwaysMatch": {"acceptInsecureCerts": true}}}
1703059699627   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1703059699628   geckodriver::capabilities   DEBUG   Found version 121.0
1703059699635   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/27/xpnvcsbs0nlfbb4qq397z3rh0000gn/T/rust_mozprofileiAWalN"
1703059699694   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1703059699694   geckodriver::browser    TRACE   Failed to open /var/folders/27/xpnvcsbs0nlfbb4qq397z3rh0000gn/T/rust_mozprofileiAWalN/MarionetteActivePort
1703059699694   geckodriver::marionette TRACE   Retrying in 100ms
1703059699798   geckodriver::browser    DEBUG   Browser process stopped: signal: 9 (SIGKILL)
1703059699799   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}

whimboo commented 6 months ago

We started a discussion on Matrix in the browsertime channel. We are going to post an update once we have more information.

tomak commented 6 months ago

Hi,

got the same problem, all tests now are not starting:

1703081227910 geckodriver INFO Listening on 127.0.0.1:59078 1703081228298 geckodriver::capabilities DEBUG Trying to read firefox version from ini files 1703081228300 geckodriver::capabilities DEBUG Found version 121.0 1703081228313 mozrunner::runner INFO Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/App ... alhost:49730/" "-foreground" "-no-remote" "-profile" "/var/folders/4m/sxnm9r15469f5krg5pr2vts80000gn/T/rust_mozprofilecsF7JW" 1703081228364 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1 1703081228364 geckodriver::browser TRACE Failed to open /var/folders/4m/sxnm9r15469f5krg5pr2vts80000gn/T/rust_mozprofilecsF7JW/MarionetteActivePort 1703081228364 geckodriver::marionette TRACE Retrying in 100ms 1703081228469 geckodriver::browser DEBUG Browser process stopped: signal: 9 (SIGKILL) 1703081228471 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}} Exception in thread "main" org.openqa.selenium.SessionNotCreatedException: Could not start a new session. Response code 500. Message: Process unexpectedly closed with status signal Build info: version: '4.3.0', revision: 'a4995e2c09*' System info: host: 'MAPV244YCXHW', ip: 'fe80:0:0:0:48b:ea78:1429:d7b8%en0', os.name: 'Mac OS X', os.arch: 'aarch64', os.version: '14.2.1', java.version: '1.8.0_345' Driver info: org.openqa.selenium.firefox.FirefoxDriver Command: [null, newSession {capabilities=[Capabilities {acceptInsecureCerts: true, browserName: firefox, moz:debuggerAddress: true, moz:firefoxOptions: {log: {level: trace}}}], desiredCapabilities=Capabilities {acceptInsecureCerts: true, browserName: firefox, moz:debuggerAddress: true, moz:firefoxOptions: {log: {level: trace}}}}] at org.openqa.selenium.remote.ProtocolHandshake.createSession(ProtocolHandshake.java:144) at org.openqa.selenium.remote.ProtocolHandshake.createSession(ProtocolHandshake.java:102) at org.openqa.selenium.remote.ProtocolHandshake.createSession(ProtocolHandshake.java:67) at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:156) at org.openqa.selenium.remote.service.DriverCommandExecutor.invokeExecute(DriverCommandExecutor.java:167) at org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:142) at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:569) at org.openqa.selenium.remote.RemoteWebDriver.startSession(RemoteWebDriver.java:264) at org.openqa.selenium.remote.RemoteWebDriver.<init>(RemoteWebDriver.java:179) at org.openqa.selenium.firefox.FirefoxDriver.<init>(FirefoxDriver.java:110) at org.openqa.selenium.firefox.FirefoxDriver.<init>(FirefoxDriver.java:98)

whimboo commented 6 months ago

@tomak do you have some more details of what you are running? Which OS version etc? Where is Firefox installed? Does it fail in both headless and headfull mode?

Also I would be kinda interested in the Firefox logs that should be visible but so far we were not able to get these. Even not when running WebDriver commands directly with curl (see our docs). Thanks!

whimboo commented 6 months ago

Also if the 120 release is still working fine for you maybe you could check for a regression range with the help of mozregression? A command like the following will do the checks on its own when you pass in a Selenium script that fails:

mozregression --good 120 --bad 121 -c '%script% --binary "{binary}"'

If you cannot pass-in the binary that way you can read the value from the MOZREGRESSION_BINARY environment variable.

soulgalore commented 6 months ago

I tested a couple of things:

Run without a specific profile, that didn't help.
Downgrade to 120 works, upgrading again makes it fail.
I runned mozregression but what is strange is that then 121 works? mozregression --good 120.0 --bad 121.0 -c "browsertime -b firefox https://www.wikipedia.org -n 1 --firefox.binaryPath {binary}" - when I manually download versions I do it from https://archive.mozilla.org/pub/firefox/releases/ - is mozregression using the same, it's strange.
This is also failing on our Mac GitHub action, thats how I first saw the error. I tried to do the simplest test case and I get the same result (click on "Test" to see the log).
I tested with headless and got the same result.

psiinon commented 6 months ago

I'm also having problems on a Mac M2. Wont bother adding to the noize but can test any potential fixes if that helps.

lprimak commented 6 months ago

Same here. Selenium tests are failing with 121, 120.0.1 works.

soulgalore commented 6 months ago

Can you please check the test case and the result (click on "Test" to see the log), that should make it reproducible for you? Please let me know if I should tune that or fix it in any way.

whimboo commented 6 months ago

@soulgalore mozregression might actually download Nighltly builds directly. Please check the first lines of the log output.

This is really strange! So I can perfectly run browsertime -b firefox https://www.wikipedia.org -n 1 --firefox.binaryPath %path% on my Mac M1 without any problems. So I really wonder what makes it specific to all of you. Could anyone please specify some details about the system configuration like the following:

MacOS version?
MacBook model?
Which locale of Firefox did you download? (mozdownload uses en-US)
Location of the Firefox binary?
Account with limited permissions?
Anything else that could help to get an idea what's common to get this reproduced

Also does the crash happen with beta releases? Those can also be found under https://archive.mozilla.org/pub/firefox/releases/. Please definitely check the 121.0b1 first.

lprimak commented 6 months ago

OS: Monterey and Sonoma
MacBook: both 2015 Intel Macbook Pro and Mac Mini M1 from 2022
Firefox downloaded / installed via Homebrew
Located in /opt/homebrew/bin/firefox
Account without admin permissions, but a "regular" account

tomak commented 6 months ago

@tomak do you have some more details of what you are running? Which OS version etc? Where is Firefox installed? Does it fail in both headless and headfull mode?

Also I would be kinda interested in the Firefox logs that should be visible but so far we were not able to get these. Even not when running WebDriver commands directly with curl (see our docs). Thanks!

Hi,

we think it is nto related to specific setup but just firefox 121 + gecko driver 033 is corrupted.

We have Firefox 121
Gecko driver 0.33
Mac OS Sonoma 14.2.1
Apple M1 Pro

jgosmann commented 6 months ago

Same problem with

Firefox 121
Gecko driver 0.33
macOS Ventura 13.6.3
Apple M2 Max

Is there any workaround apart from downgrading?

whimboo commented 6 months ago

Could you please check if the 121b1 release is also affected? https://archive.mozilla.org/pub/firefox/releases/121.0b1/mac/en-US/

jgosmann commented 6 months ago

Yes, it seems also affected. (I renamed the current Firefox in Applications and put the 121b1 there with the name Firefox, so I assume that the geckodriver will try to start that one and not the renamed release.)

whimboo commented 6 months ago

That's correct. So given that 121.0b1 is affected as well I would like to know now if a Nightly build of Firefox shows the same problem. Therefore can you please test the latest Firefox Nightly build from Nov 20th?

https://archive.mozilla.org/pub/firefox/nightly/2023/11/2023-11-20-09-52-46-mozilla-central/firefox-121.0a1.en-US.mac.dmg

soulgalore commented 6 months ago

I get the same with Nightly 123.0a1 (2023-12-21). I'm on a Macbook Pro 15-inch, 2018, running 14.2.1 using en-US.

Ok I actually got it to work :D Using /Applications/Firefox.app/Contents/MacOS/firefox instead of /Applications/Firefox.app/Contents/MacOS/firefox-bin

I think Selenium automatically sets the paths with the firefox-bin? Has anything changed with that for the latest release?

lprimak commented 6 months ago

Ok, I can confirm the above:

MacOS % ./firefox
* starts normally
MacOS % ./firefox-bin 
zsh: killed     ./firefox-bin
MacOS % pwd
/usr/local/Caskroom/firefox/121.0/Firefox.app/Contents/MacOS
MacOS %

lprimak commented 6 months ago

There may be an additional issue involved here: Prior to FF 121, tests in headless mode were able to run on a Mac when the user is not logged-in on the console (true headless). This is not working anymore since 121. The user has to be logged in on the console to work when Firefox is in headless mode. BTW: this is also an issue in Chrome. Would be nice to find out what happened with FF here.

whimboo commented 6 months ago

I've filed https://bugzilla.mozilla.org/show_bug.cgi?id=1871447 for the regression in Firefox.

We most likely will have to fix it as well for geckodriver. But not sure if we can get a quick bug fix release out. I'm going to investigate and will file a bug as well.

whimboo commented 6 months ago

I've filed an issue for Selenium so that they no longer default to firefox-bin and specify that as binary for geckodriver. In such a case we do not auto-detect the binary ourselves anymore.

whimboo commented 6 months ago

I'm going to take care of geckodriver over on https://bugzilla.mozilla.org/show_bug.cgi?id=1871458.

whimboo commented 6 months ago

As we noticed together with the Selenium team the issue only occurs when tests / clients use the old helper functions for Firefox instead of the Selenium Manager. So if you are impacted please switch over to using the Selenium Manager for browser management, or specify the path to the binary yourself.

lprimak commented 6 months ago

Filed a Mozilla bug https://bugzilla.mozilla.org/show_bug.cgi?id=1872516 for MacOS hang-on-startup headless regression.

whimboo commented 6 months ago

Filed a Mozilla bug https://bugzilla.mozilla.org/show_bug.cgi?id=1872516 for MacOS hang-on-startup headless regression.

Thanks for investigating and filing the issue! Lets see that we can get it fixed as well, but it's indeed unrelated to this particular issue.

mikz commented 6 months ago

Interestingly it fails for me with firefox. I'm using SeleniumManager and it fails after upgrading to Firefox 121 from 120.

2024-01-02 22:34:07 DEBUG Selenium [:selenium_manager] Selenium Manager binary found at /Users/mikz/.gem/ruby/3.2.2/gems/selenium-webdriver-4.16.0/bin/macos/selenium-manager
2024-01-02 22:34:07 DEBUG Selenium [:selenium_manager] Executing Process ["/Users/mikz/.gem/ruby/3.2.2/gems/selenium-webdriver-4.16.0/bin/macos/selenium-manager", "--browser", "firefox", "--output", "json", "--debug"]
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] geckodriver not found in PATH
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] firefox detected at /Applications/Firefox.app/Contents/MacOS/firefox
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Running command: /Applications/Firefox.app/Contents/MacOS/firefox -v
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Output: "Mozilla Firefox 121.0"
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Detected browser: firefox 121.0
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Required driver: geckodriver 0.33.0
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] geckodriver 0.33.0 already in the cache
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Driver path: /Users/mikz/.cache/selenium/geckodriver/mac64/0.33.0/geckodriver
2024-01-02 22:34:08 DEBUG Selenium [:selenium_manager] Browser path: /Applications/Firefox.app/Contents/MacOS/firefox
Running 4 tests in a single process (parallelization threshold is 50)
Started with run options --seed 32251

2024-01-02 22:34:08 DEBUG Selenium [:driver_service] Executing Process ["/Users/mikz/.cache/selenium/geckodriver/mac64/0.33.0/geckodriver", "--port=4444", "-vv"] -=---=---=---=---=---=---=---=---=---=---=---=---=---] 0% Time: 00:00:00,  ETA: ??:??:??
2024-01-02 22:34:08 DEBUG Selenium [:process] Starting process: ["/Users/mikz/.cache/selenium/geckodriver/mac64/0.33.0/geckodriver", "--port=4444", "-vv"] with {[:out, :err]=>#<IO:<STDOUT>>, :pgroup=>true}
2024-01-02 22:34:08 DEBUG Selenium [:process]   -> pid: 82081
2024-01-02 22:34:08 DEBUG Selenium [:driver_service] polling for socket on ["127.0.0.1", 4444]
1704231249028   geckodriver INFO    Listening on 127.0.0.1:4444
2024-01-02 22:34:09 DEBUG Selenium [:command] -> POST session
2024-01-02 22:34:09 DEBUG Selenium [:command]    >>> http://127.0.0.1:4444/session | {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{},"moz:debuggerAddress":true}}}
2024-01-02 22:34:09 DEBUG Selenium [:header]      > {"Accept"=>"application/json", "Content-Type"=>"application/json; charset=UTF-8", "User-Agent"=>"selenium/4.16.0 (ruby macosx)", "Content-Length"=>"136"}
1704231249288   webdriver::server   DEBUG   -> POST /session {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{},"moz:debuggerAddress":true}}}
1704231249289   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1704231249304   geckodriver::capabilities   DEBUG   Found version 121.0
1704231249314   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/App ... s" "localhost" "-foreground" "-no-remote" "-profile" "/var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofiletHIoIS"
1704231249369   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1704231249369   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofiletHIoIS/MarionetteActivePort
1704231249369   geckodriver::marionette TRACE   Retrying in 100ms
1704231249473   geckodriver::browser    DEBUG   Browser process stopped: signal: 9 (SIGKILL)
1704231249474   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}
2024-01-02 22:34:09 DEBUG Selenium [:header]    <<<  {"content-type"=>["application/json; charset=utf-8"], "cache-control"=>["no-cache"], "content-length"=>["110"], "date"=>["Tue, 02 Jan 2024 21:34:09 GMT"]}
2024-01-02 22:34:09 DEBUG Selenium [:command] <- {"value":{"error":"unknown error","message":"Process unexpectedly closed with status signal","stacktrace":""}}

whimboo commented 6 months ago

@mikz when you are running the test can you please check the output in the Console.app by filtering for Firefox? Copying and pasting the output would be great. Also please try to run the tests with the trace logs enabled for geckodriver. Thanks.

whimboo commented 6 months ago

Anyone affected by this problem could you please try a nightly build of the upcoming geckodriver 0.34.0? Does it fix the issue for you?

havarpan commented 6 months ago

Anyone affected by this problem could you please try a nightly build of the upcoming geckodriver 0.34.0? Does it fix the issue for you?

Yes! Thanks.

kadoppe commented 6 months ago

@whimboo

Does it fix the issue for you?

Yes. It seems that Firefox has been launched successfully.

environment

macOS: 14.2.1
Firefox: 121.0
Apple M1 Pro

geckodriver version

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

execute geckodriver

geckodriver --log trace

send request to geckodriver

curl -H 'Content-Type: application/json' -d '{"capabilities": {"alwaysMatch": {"acceptInsecureCerts": true}}}' http://localhost:4444/session

result

geckodriver's log

1704265571668   geckodriver     INFO    Listening on 127.0.0.1:4444
1704265574203   webdriver::server       DEBUG   -> POST /session {"capabilities": {"alwaysMatch": {"acceptInsecureCerts": true}}}
1704265574205   geckodriver::capabilities       DEBUG   Trying to read firefox version from ini files
1704265574206   geckodriver::capabilities       DEBUG   Trying to read firefox version from binary
1704265574408   geckodriver::capabilities       DEBUG   Found version 121.0
1704265574411   mozrunner::runner       INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/opt ... "--marionette" "-foreground" "-no-remote" "-profile" "/var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc"
1704265574412   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1704265574412   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574412   geckodriver::marionette TRACE   Retrying in 100ms
1704265574517   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574517   geckodriver::marionette TRACE   Retrying in 100ms
1704265574622   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574622   geckodriver::marionette TRACE   Retrying in 100ms
console.warn: services.settings: Ignoring preference override of remote settings server
console.warn: services.settings: Allow by setting MOZ_REMOTE_SETTINGS_DEVTOOLS=1 in the environment
1704265574723   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574723   geckodriver::marionette TRACE   Retrying in 100ms
1704265574825   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574825   geckodriver::marionette TRACE   Retrying in 100ms
1704265574825   Marionette      INFO    Marionette enabled
1704265574826   RemoteAgent     DEBUG   Setting recommended pref apz.content_response_timeout to 60000
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.contentblocking.introCount to 99
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.download.panel.shown to true
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.newtabpage.activity-stream.showSponsoredTopSites to false
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.newtabpage.enabled to false
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.pagethumbnails.capturing_disabled to true
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.region.network.url to
1704265574826   RemoteAgent     DEBUG   Setting recommended pref browser.safebrowsing.blockedURIs.enabled to false
1704265574827   RemoteAgent     DEBUG   Setting recommended pref browser.safebrowsing.downloads.enabled to false
1704265574827   RemoteAgent     DEBUG   Setting recommended pref browser.safebrowsing.malware.enabled to false
1704265574827   RemoteAgent     DEBUG   Setting recommended pref browser.safebrowsing.phishing.enabled to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.search.update to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.startup.couldRestoreSession.count to -1
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.tabs.closeWindowWithLastTab to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.tabs.unloadOnLowMemory to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.tabs.warnOnClose to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.tabs.warnOnOpen to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.toolbars.bookmarks.visibility to never
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.topsites.contile.enabled to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.usedOnWindows10.introURL to
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.urlbar.merino.endpointURL to
1704265574828   RemoteAgent     DEBUG   Setting recommended pref browser.urlbar.suggest.searches to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref dom.disable_open_during_load to false
1704265574828   RemoteAgent     DEBUG   Setting recommended pref dom.file.createInChild to true
1704265574828   RemoteAgent     DEBUG   Setting recommended pref dom.input_events.security.minNumTicks to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.input_events.security.minTimeElapsedInMS to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.max_chrome_script_run_time to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.max_script_run_time to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.navigation.locationChangeRateLimit.count to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.push.connection.enabled to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.screenorientation.allow-lock to true
1704265574829   RemoteAgent     DEBUG   Setting recommended pref dom.successive_dialog_time_limit to 0
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.getAddons.cache.enabled to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.getAddons.discovery.api_url to data:,
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.blocklist.detailsURL to http://%(server)s/extensions-dummy/blocklistDetailsURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.blocklist.itemURL to http://%(server)s/extensions-dummy/blocklistItemURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.hotfix.url to http://%(server)s/extensions-dummy/hotfixURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.systemAddon.update.url to http://%(server)s/dummy-system-addons.xml
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.update.background.url to http://%(server)s/extensions-dummy/updateBackgroundURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.update.url to http://%(server)s/extensions-dummy/updateURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.getAddons.get.url to http://%(server)s/extensions-dummy/repositoryGetURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref extensions.getAddons.search.browseURL to http://%(server)s/extensions-dummy/repositoryBrowseURL
1704265574829   RemoteAgent     DEBUG   Setting recommended pref geo.provider.network.url to
1704265574829   RemoteAgent     DEBUG   Setting recommended pref identity.fxaccounts.auth.uri to https://{server}/dummy/fxa
1704265574829   RemoteAgent     DEBUG   Setting recommended pref network.connectivity-service.enabled to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref network.http.phishy-userpass-length to 255
1704265574829   RemoteAgent     DEBUG   Setting recommended pref network.http.prompt-temp-redirect to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref privacy.trackingprotection.enabled to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref security.fileuri.strict_origin_policy to false
1704265574829   RemoteAgent     DEBUG   Setting recommended pref security.notification_enable_delay to 0
1704265574830   RemoteAgent     DEBUG   Setting recommended pref security.remote_settings.intermediates.enabled to false
1704265574830   RemoteAgent     DEBUG   Setting recommended pref signon.autofillForms to false
1704265574830   RemoteAgent     DEBUG   Setting recommended pref signon.rememberSignons to false
1704265574830   RemoteAgent     DEBUG   Setting recommended pref toolkit.telemetry.server to https://%(server)s/telemetry-dummy/
1704265574830   RemoteAgent     DEBUG   Setting recommended pref widget.windows.window_occlusion_tracking.enabled to false
1704265574830   RemoteAgent     DEBUG   Setting recommended pref dom.disable_beforeunload to true
1704265574929   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265574929   geckodriver::marionette TRACE   Retrying in 100ms
1704265575032   geckodriver::browser    TRACE   Failed to open /var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc/MarionetteActivePort
1704265575032   geckodriver::marionette TRACE   Retrying in 100ms
1704265575076   Marionette      TRACE   Received observer notification final-ui-startup
1704265575128   Marionette      INFO    Listening on port 60048
1704265575129   Marionette      DEBUG   Marionette is listening
Read port: 60048
1704265575251   Marionette      DEBUG   Accepted connection 0 from 127.0.0.1:60049
1704265575266   geckodriver::marionette DEBUG   Connection to Marionette established on 127.0.0.1:60048.
1704265575391   Marionette      DEBUG   0 -> [0,1,"WebDriver:NewSession",{"acceptInsecureCerts":true}]
1704265575392   RemoteAgent     WARN    TLS certificate errors will be ignored for this session
1704265575401   Marionette      DEBUG   Waiting for initial application window
1704265576516   Marionette      TRACE   Received observer notification browser-idle-startup-tasks-finished
1704265576520   RemoteAgent     TRACE   [9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
1704265576520   RemoteAgent     TRACE   [9] ProgressListener Setting unload timer (5000ms)
1704265576520   RemoteAgent     TRACE   [9] Document already finished loading: about:blank
1704265576520   RemoteAgent     TRACE   [9] ProgressListener Stop: has error=false
1704265576528   Marionette      DEBUG   0 <- [1,1,null,{"sessionId":"3a5859c8-23ae-4d64-9561-2d4536d83652","capabilities":{"browserName":"firefox","browserVersion":"121.0","platformName":"mac","acceptInsecureCerts":true,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":false,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20231211174248","moz:headless":false,"moz:platformVersion":"23.2.0","moz:processID":23502,"moz:profile":"/var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
1704265576531   webdriver::server       DEBUG   <- 200 OK {"value":{"sessionId":"3a5859c8-23ae-4d64-9561-2d4536d83652","capabilities":{"acceptInsecureCerts":true,"browserNam ... ctability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}

curl result

{"value":{"sessionId":"3a5859c8-23ae-4d64-9561-2d4536d83652","capabilities":{"acceptInsecureCerts":true,"browserName":"firefox","browserVersion":"121.0","moz:accessibilityChecks":false,"moz:buildID":"20231211174248","moz:geckodriverVersion":"0.34.0","moz:headless":false,"moz:platformVersion":"23.2.0","moz:processID":23502,"moz:profile":"/var/folders/xp/3rl8pw253fl4c7kkklc8cc580000gn/T/rust_mozprofile26mUSc","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"pageLoadStrategy":"normal","platformName":"mac","proxy":{},"setWindowRect":true,"strictFileInteractability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}⏎

whimboo commented 6 months ago

That's great and thanks for the confirmation. As such I'm going ahead and will release the version today.

mikz commented 6 months ago

@whimboo I'm starting geckodriver with -vv which should be the trace logs. Here it is the console.app log:

default 09:04:46.516673+0100    firefox [0x10a456d40] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.agent
default 09:04:46.521589+0100    firefox [0x10a4575b0] activating connection: mach=true listener=false peer=false name=com.apple.distributed_notifications@Uv3
default 09:04:46.523399+0100    firefox [0x10a498680] activating connection: mach=true listener=false peer=false name=com.apple.lsd.mapdb
default 09:04:46.529683+0100    firefox [0x10a457970] activating connection: mach=true listener=false peer=false name=com.apple.tccd.system
default 09:04:46.530949+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=29255.1, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, requesting={TCCDProcess: identifier=org.mozilla.firefox, pid=29255, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, },
default 09:04:46.566535+0100    firefox [0x10a457970] invalidated after the last release of the connection object
default 09:04:46.566900+0100    firefox server port 0x00004307, session port 0x00004307
default 09:04:46.568622+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=199.2326, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, accessing={TCCDProcess: identifier=org.mozilla.firefox, pid=29255, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, requesting={TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer}, },
default 09:04:46.568705+0100    tccd    requestor: TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer is checking access for accessor TCCDProcess: identifier=org.mozilla.firefox, pid=29255, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox
default 09:04:46.607642+0100    firefox [0x10a456a70] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.launchservicesd
default 09:04:46.608735+0100    firefox [0x10a457970] activating connection: mach=true listener=false peer=false name=com.apple.analyticsd
default 09:04:46.609551+0100    firefox Received configuration update from daemon (initial)
default 09:04:46.612066+0100    firefox New connection 0x9f76b main
default 09:04:46.617085+0100    firefox CHECKIN: pid=29255
default 09:04:46.631891+0100    runningboardd   Resolved pid 29255 to [anon<firefox>(501):29255]
default 09:04:46.633004+0100    launchservicesd CHECKIN:0x0-0xca8ca8 29255 org.mozilla.firefox
default 09:04:46.632361+0100    runningboardd   [anon<firefox>(501):29255] Memory Limits: active 0 inactive 0
 <private>
default 09:04:46.632427+0100    runningboardd   [anon<firefox>(501):29255] This process will not be managed.
default 09:04:46.633485+0100    firefox CHECKEDIN: pid=29255 asn=0x0-0xca8ca8 foreground=1
default 09:04:46.632481+0100    runningboardd   Now tracking process: [anon<firefox>(501):29255]
default 09:04:46.633368+0100    loginwindow -[PersistentAppsSupport applicationReady:] | App: Firefox, ready, updating active tracking timer
default 09:04:46.634242+0100    lockoutagent    Requesting policy for bundle IDs: (
    "org.mozilla.firefox"
)
default 09:04:46.633445+0100    loginwindow -[ApplicationManager checkInAppContext:eventData:] | ApplicationManager: Checked in app : Firefox
default 09:04:46.634701+0100    firefox [0x10a499230] activating connection: mach=true listener=false peer=false name=com.apple.lsd.modifydb
default 09:04:46.633128+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29255] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29255" ID:215-170-72335 target:29255 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:04:46.633441+0100    runningboardd   Assertion 215-170-72335 (target:[anon<firefox>(501):29255]) will be created as active
default 09:04:46.635829+0100    firefox [0x10dbe2820] activating connection: mach=false listener=true peer=false name=(anonymous)
default 09:04:46.636147+0100    firefox [0x10a4a7bd0] activating connection: mach=false listener=false peer=true name=com.apple.xpc.anonymous.0x10dbe2820.peer.0x10a4a7bd0
default 09:04:46.636765+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29255] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29255" ID:215-170-72336 target:29255 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:04:46.639734+0100    lockoutagent    Requested application org.mozilla.firefox has policy OK, associated categories:DH1005 associated sites: equivalent bundle identifiers:org.mozilla.ios.Firefox,org.mozilla.firefox
default 09:04:46.637613+0100    runningboardd   Assertion 215-170-72336 (target:[anon<firefox>(501):29255]) will be created as active
default 09:04:46.636775+0100    runningboardd   [anon<firefox>(501):29255] Ignoring jetsam update because this process is not memory-managed
default 09:04:46.639820+0100    runningboardd   [anon<firefox>(501):29255] Ignoring suspend because this process is not lifecycle managed
default 09:04:46.640522+0100    runningboardd   [anon<firefox>(501):29255] Set darwin role to: UserInteractiveNonFocal
default 09:04:46.640952+0100    firefox FRONTLOGGING: version 1
default 09:04:46.641259+0100    firefox Registered, pid=29255 ASN=0x0,0xca8ca8
default 09:04:46.641083+0100    runningboardd   [anon<firefox>(501):29255] Ignoring GPU update because this process is not GPU managed
default 09:04:46.643058+0100    runningboardd   Invalidating assertion 215-170-72335 (target:[anon<firefox>(501):29255]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:04:46.642465+0100    runningboardd   [anon<firefox>(501):29255] Ignoring memory limit update because this process is not memory-managed
default 09:04:46.647398+0100    firefox BringForward: pid=29255 asn=0x0-0xca8ca8 bringForward=0 foreground=1 uiElement=0 launchedByLS=0 modifiersCount=0 allDisabled=0
default 09:04:46.657330+0100    distnoted   register name: com.apple.sharedfilelist.change object: com.apple.LSSharedFileList.ApplicationRecentDocuments/org.mozilla.firefox token: 11a0000003c pid: 2787
default 09:04:46.658713+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:04:46.661673+0100    firefox No persisted cache on this platform.
default 09:04:46.662765+0100    firefox Failed to copy the SysCfgDict MG key with error: 0
default 09:04:46.665173+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:04:46.666306+0100    firefox Post-registration system appearance: (HLTB: 1)
default 09:04:46.717881+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:1:1:Building bundle record for app
default 09:04:46.718118+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:2:1:Built bundle record for app
default 09:04:46.761934+0100    distnoted   register name: com.apple.xctest.FakeForceTouchDevice object: org.mozilla.firefox token: 1c0000001f pid: 29255
default 09:04:46.775202+0100    firefox Entering exit handler.
default 09:04:46.775249+0100    firefox Queueing exit procedure onto XPC queue. Any further messages sent will be discarded. activeSendTransactions=0
default 09:04:46.775429+0100    firefox Cancelling XPC connection. Any further reply handler invocations will not retry messages
default 09:04:46.775455+0100    firefox [0x10a457970] invalidated on xpc_connection_cancel()
default 09:04:46.775501+0100    firefox Exiting exit handler.
default 09:04:46.775527+0100    firefox XPC connection invalidated (daemon unloaded/disabled)
default 09:04:46.780575+0100    runningboardd   [anon<firefox>(501):29255] termination reported by proc_exit
default 09:04:46.786611+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | for app:Firefox, _appTrackingState = 2
default 09:04:46.786657+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | App: Firefox, quit, updating active tracking timer
default 09:04:46.787602+0100    runningboardd   Invalidating assertion 215-170-72336 (target:[anon<firefox>(501):29255]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:04:46.882069+0100    runningboardd   Removing process: [anon<firefox>(501):29255]
default 09:04:46.882220+0100    runningboardd   removeJobWithInstance called for identity without existing job [anon<firefox>(501):29255]
default 09:04:46.882253+0100    runningboardd   Removing assertions for terminated process: [anon<firefox>(501):29255]
error   09:04:46.904490+0100    runningboardd   RBSStateCapture remove item called for untracked item 215-170-72336 (target:[anon<firefox>(501):29255])
default 09:04:47.491012+0100    kernel  Checking in with amfid for DER firefox-bin
default 09:04:47.491425+0100    kernel  AMFI: /Applications/Firefox.app/Contents/MacOS/firefox-bin doesn't have DER entitlements and will not work in a future release
error   09:04:47.502700+0100    taskgated-helper    Disallowing firefox-bin because no eligible provisioning profiles found
default 09:04:47.504188+0100    amfid   /Applications/Firefox.app/Contents/MacOS/firefox-bin not valid: Error Domain=AppleMobileFileIntegrityError Code=-413 "No matching profile found" UserInfo={NSURL=file:///Applications/Firefox.app/Contents/MacOS/firefox-bin, NSLocalizedDescription=No matching profile found}
default 09:04:47.504445+0100    kernel  AMFI: Releasing transmuted blob for firefox-bin - <private> 474x
default 09:04:47.504564+0100    kernel  proc 29258: load code signature error 4 for file "firefox-bin"
default 09:04:47.505220+0100    kernel  firefox-bin[29258] Corpse allowed 1 of 5
default 09:04:47.515680+0100    ReportCrash Formulating fatal 309 report for corpse[29258] firefox-bin
default 09:04:47.519424+0100    ReportCrash no MetricKit for process firefox-bin type 309 bundleId (null)
default 09:04:47.890235+0100    kernel  Checking in with amfid for DER firefox-bin
default 09:04:47.890690+0100    kernel  AMFI: /Applications/Firefox.app/Contents/MacOS/firefox-bin doesn't have DER entitlements and will not work in a future release
error   09:04:47.902283+0100    taskgated-helper    Disallowing firefox-bin because no eligible provisioning profiles found
default 09:04:47.903650+0100    amfid   /Applications/Firefox.app/Contents/MacOS/firefox-bin not valid: Error Domain=AppleMobileFileIntegrityError Code=-413 "No matching profile found" UserInfo={NSURL=file:///Applications/Firefox.app/Contents/MacOS/firefox-bin, NSLocalizedDescription=No matching profile found}
default 09:04:47.903898+0100    kernel  AMFI: Releasing transmuted blob for firefox-bin - <private> 474x
default 09:04:47.904006+0100    kernel  proc 29261: load code signature error 4 for file "firefox-bin"
default 09:04:47.904635+0100    kernel  firefox-bin[29261] Corpse allowed 1 of 5
default 09:04:47.915874+0100    ReportCrash Formulating fatal 309 report for corpse[29261] firefox-bin
default 09:04:47.919456+0100    ReportCrash no MetricKit for process firefox-bin type 309 bundleId (null)
error   09:05:34.684055+0100    kernel  System Policy: SystemUIServer(2788) deny(1) file-read-xattr /Users/mikz/Downloads/Firefox 120.0.1.dmg

And trying it with the latest geckodriver nightly works!

2024-01-03 09:08:10 DEBUG Selenium [:selenium_manager] Selenium Manager binary found at /Users/mikz/.gem/ruby/3.2.2/gems/selenium-webdriver-4.16.0/bin/macos/selenium-manager
2024-01-03 09:08:10 DEBUG Selenium [:selenium_manager] Executing Process ["/Users/mikz/.gem/ruby/3.2.2/gems/selenium-webdriver-4.16.0/bin/macos/selenium-manager", "--browser", "firefox", "--output", "json", "--debug"]
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Found geckodriver 0.34.0 in PATH: /usr/local/bin/geckodriver
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] firefox detected at /Applications/Firefox.app/Contents/MacOS/firefox
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Running command: /Applications/Firefox.app/Contents/MacOS/firefox -v
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Output: "Mozilla Firefox 121.0"
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Detected browser: firefox 121.0
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Required driver: geckodriver 0.33.0
2024-01-03 09:08:11 WARN Selenium [:selenium_manager] The geckodriver version (0.34.0) detected in PATH at /usr/local/bin/geckodriver might not be compatible with the detected firefox version (121.0); currently, geckodriver 0.33.0 is recommended for firefox 121.*, so it is advised to delete the driver in PATH and retry
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Driver path: /usr/local/bin/geckodriver
2024-01-03 09:08:11 DEBUG Selenium [:selenium_manager] Browser path: /Applications/Firefox.app/Contents/MacOS/firefox
Running 4 tests in a single process (parallelization threshold is 50)
Started with run options -n test_sign_up --seed 58672

2024-01-03 09:08:11 DEBUG Selenium [:driver_service] Executing Process ["/usr/local/bin/geckodriver", "--port=4444", "-vv"] ---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---] 0% Time: 00:00:00,  ETA: ??:??:??
2024-01-03 09:08:11 DEBUG Selenium [:process] Starting process: ["/usr/local/bin/geckodriver", "--port=4444", "-vv"] with {[:out, :err]=>#<IO:<STDOUT>>, :pgroup=>true}
2024-01-03 09:08:11 DEBUG Selenium [:process]   -> pid: 29470
2024-01-03 09:08:11 DEBUG Selenium [:driver_service] polling for socket on ["127.0.0.1", 4444]
1704269291527   geckodriver INFO    Listening on 127.0.0.1:4444
2024-01-03 09:08:11 DEBUG Selenium [:command] -> POST session
2024-01-03 09:08:11 DEBUG Selenium [:command]    >>> http://127.0.0.1:4444/session | {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{},"moz:debuggerAddress":true}}}
2024-01-03 09:08:11 DEBUG Selenium [:header]      > {"Accept"=>"application/json", "Content-Type"=>"application/json; charset=UTF-8", "User-Agent"=>"selenium/4.16.0 (ruby macosx)", "Content-Length"=>"136"}
1704269291784   webdriver::server   DEBUG   -> POST /session {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{},"moz:debuggerAddress":true}}}
1704269291785   geckodriver::capabilities   DEBUG   Trying to read firefox version from ini files
1704269291785   geckodriver::capabilities   DEBUG   Trying to read firefox version from binary
1704269292331   geckodriver::capabilities   DEBUG   Found version 121.0
1704269292345   mozrunner::runner   INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/usr ... s" "localhost" "-foreground" "-no-remote" "-profile" "/var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim"
1704269292346   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1
1704269292346   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292346   geckodriver::marionette TRACE   Retrying in 100ms
1704269292447   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292447   geckodriver::marionette TRACE   Retrying in 100ms
1704269292548   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292548   geckodriver::marionette TRACE   Retrying in 100ms
1704269292649   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292649   geckodriver::marionette TRACE   Retrying in 100ms
1704269292753   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292753   geckodriver::marionette TRACE   Retrying in 100ms
console.warn: services.settings: Ignoring preference override of remote settings server
console.warn: services.settings: Allow by setting MOZ_REMOTE_SETTINGS_DEVTOOLS=1 in the environment
1704269292854   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292854   geckodriver::marionette TRACE   Retrying in 100ms
1704269292955   geckodriver::browser    TRACE   Failed to open /var/folders/8k/zxsbw5cs0gg_ghmw_v4w3t3r0000gn/T/rust_mozprofileZmefim/MarionetteActivePort
1704269292955   geckodriver::marionette TRACE   Retrying in 100ms
1704269293054   RemoteAgent DEBUG   WebDriver BiDi enabled
1704269293055   RemoteAgent DEBUG   CDP enabled
1704269293055   Marionette  INFO    Marionette enabled
1704269293057   RemoteAgent DEBUG   Setting recommended pref apz.content_response_timeout to 60000

and the releveant console.app log

error   09:09:36.991403+0100    kernel  System Policy: SystemUIServer(2788) deny(1) file-read-xattr /Users/mikz/Downloads/Firefox 120.0.1.dmg
default 09:09:37.794104+0100    firefox [0x102156a70] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.daemon
default 09:09:37.794285+0100    firefox [0x102156b60] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.agent
default 09:09:37.799420+0100    firefox [0x102157880] activating connection: mach=true listener=false peer=false name=com.apple.distributed_notifications@Uv3
default 09:09:37.802000+0100    firefox [0x1021989b0] activating connection: mach=true listener=false peer=false name=com.apple.lsd.mapdb
default 09:09:37.807668+0100    firefox [0x102156c50] activating connection: mach=true listener=false peer=false name=com.apple.tccd.system
default 09:09:37.808960+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=29641.1, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, requesting={TCCDProcess: identifier=org.mozilla.firefox, pid=29641, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, },
default 09:09:37.844541+0100    firefox [0x102156c50] invalidated after the last release of the connection object
default 09:09:37.844882+0100    firefox server port 0x00005307, session port 0x00005307
default 09:09:37.846602+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=199.2336, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, accessing={TCCDProcess: identifier=org.mozilla.firefox, pid=29641, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, requesting={TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer}, },
default 09:09:37.846693+0100    tccd    requestor: TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer is checking access for accessor TCCDProcess: identifier=org.mozilla.firefox, pid=29641, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:37.885063+0100    firefox [0x102156980] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.launchservicesd
default 09:09:37.886286+0100    firefox [0x1021571f0] activating connection: mach=true listener=false peer=false name=com.apple.analyticsd
default 09:09:37.887221+0100    firefox Received configuration update from daemon (initial)
default 09:09:37.889777+0100    firefox New connection 0x20505f main
default 09:09:37.895782+0100    firefox CHECKIN: pid=29641
default 09:09:37.910415+0100    runningboardd   Resolved pid 29641 to [anon<firefox>(501):29641]
default 09:09:37.911375+0100    launchservicesd CHECKIN:0x0-0xcbfcbf 29641 org.mozilla.firefox
default 09:09:37.910784+0100    runningboardd   [anon<firefox>(501):29641] Memory Limits: active 0 inactive 0
 <private>
default 09:09:37.910829+0100    runningboardd   [anon<firefox>(501):29641] This process will not be managed.
default 09:09:37.911948+0100    firefox CHECKEDIN: pid=29641 asn=0x0-0xcbfcbf foreground=1
default 09:09:37.910921+0100    runningboardd   Now tracking process: [anon<firefox>(501):29641]
default 09:09:37.912288+0100    loginwindow -[PersistentAppsSupport applicationReady:] | App: Firefox, ready, updating active tracking timer
default 09:09:37.912662+0100    lockoutagent    Requesting policy for bundle IDs: (
    "org.mozilla.firefox"
)
default 09:09:37.912368+0100    loginwindow -[ApplicationManager checkInAppContext:eventData:] | ApplicationManager: Checked in app : Firefox
default 09:09:37.913557+0100    firefox [0x102198ce0] activating connection: mach=true listener=false peer=false name=com.apple.lsd.modifydb
default 09:09:37.911565+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29641] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29641" ID:215-170-72784 target:29641 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:37.911993+0100    runningboardd   Assertion 215-170-72784 (target:[anon<firefox>(501):29641]) will be created as active
default 09:09:37.915235+0100    firefox [0x1058c8700] activating connection: mach=false listener=true peer=false name=(anonymous)
default 09:09:37.915622+0100    firefox [0x1021a7f60] activating connection: mach=false listener=false peer=true name=com.apple.xpc.anonymous.0x1058c8700.peer.0x1021a7f60
default 09:09:37.915096+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29641] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29641" ID:215-170-72785 target:29641 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:37.918200+0100    lockoutagent    Requested application org.mozilla.firefox has policy OK, associated categories:DH1005 associated sites: equivalent bundle identifiers:org.mozilla.ios.Firefox,org.mozilla.firefox
default 09:09:37.916160+0100    runningboardd   Assertion 215-170-72785 (target:[anon<firefox>(501):29641]) will be created as active
default 09:09:37.915121+0100    runningboardd   [anon<firefox>(501):29641] Ignoring jetsam update because this process is not memory-managed
default 09:09:37.918055+0100    runningboardd   [anon<firefox>(501):29641] Ignoring suspend because this process is not lifecycle managed
default 09:09:37.918864+0100    runningboardd   [anon<firefox>(501):29641] Set darwin role to: UserInteractiveNonFocal
default 09:09:37.919404+0100    runningboardd   [anon<firefox>(501):29641] Ignoring GPU update because this process is not GPU managed
default 09:09:37.920105+0100    firefox FRONTLOGGING: version 1
default 09:09:37.920442+0100    firefox Registered, pid=29641 ASN=0x0,0xcbfcbf
default 09:09:37.920584+0100    runningboardd   [anon<firefox>(501):29641] Ignoring memory limit update because this process is not memory-managed
default 09:09:37.921411+0100    runningboardd   Invalidating assertion 215-170-72784 (target:[anon<firefox>(501):29641]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:37.925093+0100    firefox BringForward: pid=29641 asn=0x0-0xcbfcbf bringForward=0 foreground=1 uiElement=0 launchedByLS=0 modifiersCount=0 allDisabled=0
default 09:09:37.934710+0100    distnoted   register name: com.apple.sharedfilelist.change object: com.apple.LSSharedFileList.ApplicationRecentDocuments/org.mozilla.firefox token: 1220000003c pid: 2787
default 09:09:37.936311+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:37.940864+0100    firefox No persisted cache on this platform.
default 09:09:37.941922+0100    firefox Failed to copy the SysCfgDict MG key with error: 0
default 09:09:37.944621+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:37.946319+0100    firefox Post-registration system appearance: (HLTB: 1)
default 09:09:37.995704+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:1:1:Building bundle record for app
default 09:09:37.995949+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:2:1:Built bundle record for app
default 09:09:38.037405+0100    distnoted   register name: com.apple.xctest.FakeForceTouchDevice object: org.mozilla.firefox token: 1c0000001f pid: 29641
default 09:09:38.049593+0100    firefox Entering exit handler.
default 09:09:38.049634+0100    firefox Queueing exit procedure onto XPC queue. Any further messages sent will be discarded. activeSendTransactions=0
default 09:09:38.049765+0100    firefox Cancelling XPC connection. Any further reply handler invocations will not retry messages
default 09:09:38.049787+0100    firefox [0x1021571f0] invalidated on xpc_connection_cancel()
default 09:09:38.049823+0100    firefox Exiting exit handler.
default 09:09:38.049860+0100    firefox XPC connection invalidated (daemon unloaded/disabled)
default 09:09:38.054323+0100    runningboardd   [anon<firefox>(501):29641] termination reported by proc_exit
default 09:09:38.059478+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | for app:Firefox, _appTrackingState = 2
default 09:09:38.059514+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | App: Firefox, quit, updating active tracking timer
default 09:09:38.060652+0100    runningboardd   Invalidating assertion 215-170-72785 (target:[anon<firefox>(501):29641]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:38.159109+0100    runningboardd   Removing process: [anon<firefox>(501):29641]
default 09:09:38.159306+0100    runningboardd   removeJobWithInstance called for identity without existing job [anon<firefox>(501):29641]
default 09:09:38.159341+0100    runningboardd   Removing assertions for terminated process: [anon<firefox>(501):29641]
error   09:09:38.172925+0100    runningboardd   RBSStateCapture remove item called for untracked item 215-170-72785 (target:[anon<firefox>(501):29641])
default 09:09:38.884341+0100    firefox [0x10b256b60] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.daemon
default 09:09:38.884581+0100    firefox [0x10b2572e0] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.agent
default 09:09:38.891340+0100    firefox [0x10b2574c0] activating connection: mach=true listener=false peer=false name=com.apple.distributed_notifications@Uv3
default 09:09:38.893488+0100    firefox [0x10b299120] activating connection: mach=true listener=false peer=false name=com.apple.lsd.mapdb
default 09:09:38.899703+0100    firefox [0x10b2562f0] activating connection: mach=true listener=false peer=false name=com.apple.tccd.system
default 09:09:38.900953+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=29643.1, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, requesting={TCCDProcess: identifier=org.mozilla.firefox, pid=29643, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, },
default 09:09:38.941999+0100    firefox [0x10b2562f0] invalidated after the last release of the connection object
default 09:09:38.942538+0100    firefox server port 0x00004407, session port 0x00004407
default 09:09:38.944436+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=199.2337, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, accessing={TCCDProcess: identifier=org.mozilla.firefox, pid=29643, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, requesting={TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer}, },
default 09:09:38.944518+0100    tccd    requestor: TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer is checking access for accessor TCCDProcess: identifier=org.mozilla.firefox, pid=29643, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:38.989607+0100    firefox [0x10b2575b0] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.launchservicesd
default 09:09:38.991539+0100    firefox [0x10b257b50] activating connection: mach=true listener=false peer=false name=com.apple.analyticsd
default 09:09:38.993045+0100    firefox Received configuration update from daemon (initial)
default 09:09:38.995929+0100    firefox New connection 0x1a1e8f main
default 09:09:39.001233+0100    firefox CHECKIN: pid=29643
default 09:09:39.021087+0100    runningboardd   Resolved pid 29643 to [anon<firefox>(501):29643]
default 09:09:39.021514+0100    runningboardd   [anon<firefox>(501):29643] Memory Limits: active 0 inactive 0
 <private>
default 09:09:39.021579+0100    runningboardd   [anon<firefox>(501):29643] This process will not be managed.
default 09:09:39.021627+0100    runningboardd   Now tracking process: [anon<firefox>(501):29643]
default 09:09:39.023009+0100    launchservicesd CHECKIN:0x0-0xcc0cc0 29643 org.mozilla.firefox
default 09:09:39.022110+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29643] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29643" ID:215-170-72788 target:29643 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:39.023447+0100    firefox CHECKEDIN: pid=29643 asn=0x0-0xcc0cc0 foreground=1
default 09:09:39.022460+0100    runningboardd   Assertion 215-170-72788 (target:[anon<firefox>(501):29643]) will be created as active
default 09:09:39.023684+0100    lockoutagent    Requesting policy for bundle IDs: (
    "org.mozilla.firefox"
)
default 09:09:39.024805+0100    firefox [0x10b298240] activating connection: mach=true listener=false peer=false name=com.apple.lsd.modifydb
default 09:09:39.025367+0100    loginwindow -[PersistentAppsSupport applicationReady:] | App: Firefox, ready, updating active tracking timer
default 09:09:39.025446+0100    loginwindow -[ApplicationManager checkInAppContext:eventData:] | ApplicationManager: Checked in app : Firefox
default 09:09:39.026029+0100    firefox [0x10eac8ca0] activating connection: mach=false listener=true peer=false name=(anonymous)
default 09:09:39.026443+0100    firefox [0x10b2a7250] activating connection: mach=false listener=false peer=true name=com.apple.xpc.anonymous.0x10eac8ca0.peer.0x10b2a7250
default 09:09:39.024620+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29643] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29643" ID:215-170-72789 target:29643 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:39.025266+0100    runningboardd   Assertion 215-170-72789 (target:[anon<firefox>(501):29643]) will be created as active
default 09:09:39.030009+0100    lockoutagent    Requested application org.mozilla.firefox has policy OK, associated categories:DH1005 associated sites: equivalent bundle identifiers:org.mozilla.ios.Firefox,org.mozilla.firefox
default 09:09:39.024627+0100    runningboardd   [anon<firefox>(501):29643] Ignoring jetsam update because this process is not memory-managed
default 09:09:39.028127+0100    runningboardd   [anon<firefox>(501):29643] Ignoring suspend because this process is not lifecycle managed
default 09:09:39.028882+0100    runningboardd   [anon<firefox>(501):29643] Set darwin role to: UserInteractiveNonFocal
default 09:09:39.029716+0100    runningboardd   [anon<firefox>(501):29643] Ignoring GPU update because this process is not GPU managed
default 09:09:39.031295+0100    runningboardd   [anon<firefox>(501):29643] Ignoring memory limit update because this process is not memory-managed
default 09:09:39.031810+0100    firefox FRONTLOGGING: version 1
default 09:09:39.032093+0100    firefox Registered, pid=29643 ASN=0x0,0xcc0cc0
default 09:09:39.032284+0100    runningboardd   Invalidating assertion 215-170-72788 (target:[anon<firefox>(501):29643]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:39.038393+0100    firefox BringForward: pid=29643 asn=0x0-0xcc0cc0 bringForward=0 foreground=1 uiElement=0 launchedByLS=0 modifiersCount=0 allDisabled=0
default 09:09:39.051090+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:39.051532+0100    distnoted   register name: com.apple.sharedfilelist.change object: com.apple.LSSharedFileList.ApplicationRecentDocuments/org.mozilla.firefox token: 12400000043 pid: 2787
default 09:09:39.054656+0100    firefox No persisted cache on this platform.
default 09:09:39.055783+0100    firefox Failed to copy the SysCfgDict MG key with error: 0
default 09:09:39.058558+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:39.059686+0100    firefox Post-registration system appearance: (HLTB: 1)
default 09:09:39.116082+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:1:1:Building bundle record for app
default 09:09:39.116319+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:2:1:Built bundle record for app
default 09:09:39.157243+0100    distnoted   register name: com.apple.xctest.FakeForceTouchDevice object: org.mozilla.firefox token: 1c0000001f pid: 29643
default 09:09:39.174580+0100    firefox Entering exit handler.
default 09:09:39.174621+0100    firefox Queueing exit procedure onto XPC queue. Any further messages sent will be discarded. activeSendTransactions=0
default 09:09:39.174751+0100    firefox Cancelling XPC connection. Any further reply handler invocations will not retry messages
default 09:09:39.174787+0100    firefox [0x10b257b50] invalidated on xpc_connection_cancel()
default 09:09:39.174844+0100    firefox Exiting exit handler.
default 09:09:39.174869+0100    firefox XPC connection invalidated (daemon unloaded/disabled)
default 09:09:39.179903+0100    runningboardd   [anon<firefox>(501):29643] termination reported by proc_exit
default 09:09:39.185159+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | for app:Firefox, _appTrackingState = 2
default 09:09:39.185235+0100    loginwindow -[PersistentAppsSupport applicationQuit:] | App: Firefox, quit, updating active tracking timer
default 09:09:39.187222+0100    runningboardd   Invalidating assertion 215-170-72789 (target:[anon<firefox>(501):29643]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:39.285518+0100    runningboardd   Removing process: [anon<firefox>(501):29643]
default 09:09:39.285718+0100    runningboardd   removeJobWithInstance called for identity without existing job [anon<firefox>(501):29643]
default 09:09:39.285762+0100    runningboardd   Removing assertions for terminated process: [anon<firefox>(501):29643]
default 09:09:39.296744+0100    firefox [0x102a565b0] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.daemon
default 09:09:39.296916+0100    firefox [0x102a56100] activating connection: mach=true listener=false peer=false name=com.apple.cfprefsd.agent
default 09:09:39.303144+0100    firefox [0x102a55c50] activating connection: mach=true listener=false peer=false name=com.apple.distributed_notifications@Uv3
default 09:09:39.304842+0100    firefox [0x102aa68a0] activating connection: mach=true listener=false peer=false name=com.apple.lsd.mapdb
error   09:09:39.304805+0100    runningboardd   RBSStateCapture remove item called for untracked item 215-170-72789 (target:[anon<firefox>(501):29643])
default 09:09:39.312186+0100    firefox [0x102a555c0] activating connection: mach=true listener=false peer=false name=com.apple.tccd.system
default 09:09:39.313396+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=29644.1, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, requesting={TCCDProcess: identifier=org.mozilla.firefox, pid=29644, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, },
default 09:09:39.353784+0100    firefox [0x102a555c0] invalidated after the last release of the connection object
default 09:09:39.354402+0100    firefox server port 0x00004407, session port 0x00004407
default 09:09:39.356456+0100    tccd    AUTHREQ_ATTRIBUTION: msgID=199.2338, attribution={responsible={TCCDProcess: identifier=com.googlecode.iterm2, pid=2533, auid=501, euid=501, responsible_path=/Applications/iTerm.app/Contents/MacOS/iTerm2, binary_path=/Applications/iTerm.app/Contents/MacOS/iTerm2}, accessing={TCCDProcess: identifier=org.mozilla.firefox, pid=29644, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox}, requesting={TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer}, },
default 09:09:39.356545+0100    tccd    requestor: TCCDProcess: identifier=com.apple.WindowServer, pid=199, auid=88, euid=88, binary_path=/System/Library/PrivateFrameworks/SkyLight.framework/Versions/A/Resources/WindowServer is checking access for accessor TCCDProcess: identifier=org.mozilla.firefox, pid=29644, auid=501, euid=501, binary_path=/Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:39.403443+0100    firefox [0x102a55200] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.launchservicesd
default 09:09:39.404695+0100    firefox [0x102a56790] activating connection: mach=true listener=false peer=false name=com.apple.analyticsd
default 09:09:39.405592+0100    firefox Received configuration update from daemon (initial)
default 09:09:39.408423+0100    firefox New connection 0x1a1e97 main
default 09:09:39.413161+0100    firefox CHECKIN: pid=29644
default 09:09:39.429305+0100    runningboardd   Resolved pid 29644 to [anon<firefox>(501):29644]
default 09:09:39.429832+0100    runningboardd   [anon<firefox>(501):29644] Memory Limits: active 0 inactive 0
 <private>
default 09:09:39.430475+0100    launchservicesd CHECKIN:0x0-0xcc1cc1 29644 org.mozilla.firefox
default 09:09:39.429902+0100    runningboardd   [anon<firefox>(501):29644] This process will not be managed.
default 09:09:39.429958+0100    runningboardd   Now tracking process: [anon<firefox>(501):29644]
default 09:09:39.430928+0100    firefox CHECKEDIN: pid=29644 asn=0x0-0xcc1cc1 foreground=1
default 09:09:39.432027+0100    lockoutagent    Requesting policy for bundle IDs: (
    "org.mozilla.firefox"
)
default 09:09:39.430449+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29644] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29644" ID:215-170-72792 target:29644 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:39.430881+0100    runningboardd   Assertion 215-170-72792 (target:[anon<firefox>(501):29644]) will be created as active
default 09:09:39.432477+0100    firefox [0x102aa6020] activating connection: mach=true listener=false peer=false name=com.apple.lsd.modifydb
default 09:09:39.433656+0100    firefox [0x1062f9820] activating connection: mach=false listener=true peer=false name=(anonymous)
default 09:09:39.432959+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29644] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "foregroundApp:29644" ID:215-170-72793 target:29644 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveNonFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:39.433994+0100    firefox [0x102a9c090] activating connection: mach=false listener=false peer=true name=com.apple.xpc.anonymous.0x1062f9820.peer.0x102a9c090
default 09:09:39.436283+0100    loginwindow -[PersistentAppsSupport applicationReady:] | App: Firefox, ready, updating active tracking timer
default 09:09:39.433545+0100    runningboardd   Assertion 215-170-72793 (target:[anon<firefox>(501):29644]) will be created as active
default 09:09:39.436361+0100    loginwindow -[ApplicationManager checkInAppContext:eventData:] | ApplicationManager: Checked in app : Firefox
default 09:09:39.438982+0100    lockoutagent    Requested application org.mozilla.firefox has policy OK, associated categories:DH1005 associated sites: equivalent bundle identifiers:org.mozilla.ios.Firefox,org.mozilla.firefox
default 09:09:39.432962+0100    runningboardd   [anon<firefox>(501):29644] Ignoring jetsam update because this process is not memory-managed
default 09:09:39.438755+0100    runningboardd   [anon<firefox>(501):29644] Ignoring suspend because this process is not lifecycle managed
default 09:09:39.439476+0100    runningboardd   [anon<firefox>(501):29644] Set darwin role to: UserInteractiveNonFocal
default 09:09:39.440300+0100    firefox FRONTLOGGING: version 1
default 09:09:39.440052+0100    runningboardd   [anon<firefox>(501):29644] Ignoring GPU update because this process is not GPU managed
default 09:09:39.440582+0100    firefox Registered, pid=29644 ASN=0x0,0xcc1cc1
default 09:09:39.441256+0100    runningboardd   [anon<firefox>(501):29644] Ignoring memory limit update because this process is not memory-managed
default 09:09:39.439198+0100    runningboardd   Invalidating assertion 215-170-72792 (target:[anon<firefox>(501):29644]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:39.446819+0100    firefox BringForward: pid=29644 asn=0x0-0xcc1cc1 bringForward=0 foreground=1 uiElement=0 launchedByLS=0 modifiersCount=0 allDisabled=0
default 09:09:39.461282+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:39.465524+0100    firefox No persisted cache on this platform.
default 09:09:39.467683+0100    firefox Failed to copy the SysCfgDict MG key with error: 0
default 09:09:39.471467+0100    firefox Current system appearance, (HLTB: 1), (SLS: 0)
default 09:09:39.473366+0100    firefox Post-registration system appearance: (HLTB: 1)
default 09:09:39.524928+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:1:1:Building bundle record for app
default 09:09:39.525165+0100    lsd org.mozilla.firefox/Unknown Persona:5:5:2:1:Built bundle record for app
default 09:09:39.573319+0100    distnoted   register name: com.apple.xctest.FakeForceTouchDevice object: org.mozilla.firefox token: 1c0000001f pid: 29644
default 09:09:39.590272+0100    firefox SetFrontProcess: asn=0x0-0xcc1cc1 options=0
default 09:09:39.591862+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29644] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "frontmost:29644" ID:215-170-72794 target:29644 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"RoleUserInteractiveFocal" sourceEnvironment:"(null)">
    ]>
default 09:09:39.592001+0100    runningboardd   Assertion 215-170-72794 (target:[anon<firefox>(501):29644]) will be created as active
default 09:09:39.592560+0100    runningboardd   [anon<firefox>(501):29644] Ignoring jetsam update because this process is not memory-managed
default 09:09:39.592704+0100    runningboardd   [anon<firefox>(501):29644] Ignoring suspend because this process is not lifecycle managed
default 09:09:39.592878+0100    runningboardd   [anon<firefox>(501):29644] Set darwin role to: UserInteractiveFocal
default 09:09:39.593126+0100    runningboardd   [anon<firefox>(501):29644] Ignoring GPU update because this process is not GPU managed
default 09:09:39.594232+0100    runningboardd   [anon<firefox>(501):29644] Ignoring memory limit update because this process is not memory-managed
default 09:09:39.596179+0100    runningboardd   Acquiring assertion targeting [anon<firefox>(501):29644] from originator [osservice<com.apple.coreservices.launchservicesd>:170] with description <RBSAssertionDescriptor| "notification:29644" ID:215-170-72795 target:29644 attributes:[
    <RBSDomainAttribute| domain:"com.apple.launchservicesd" name:"LSNotification" sourceEnvironment:"(null)">
    ]>
default 09:09:39.596507+0100    runningboardd   Assertion 215-170-72795 (target:[anon<firefox>(501):29644]) will be created as active
default 09:09:39.598120+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app
default 09:09:39.598823+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app/Contents
default 09:09:39.599107+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app/Contents/Info.plist
default 09:09:39.599029+0100    runningboardd   [anon<firefox>(501):29644] Ignoring jetsam update because this process is not memory-managed
default 09:09:39.599445+0100    runningboardd   [anon<firefox>(501):29644] Ignoring suspend because this process is not lifecycle managed
default 09:09:39.600687+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app
default 09:09:39.599611+0100    runningboardd   [anon<firefox>(501):29644] Ignoring GPU update because this process is not GPU managed
default 09:09:39.599937+0100    runningboardd   [anon<firefox>(501):29644] Ignoring memory limit update because this process is not memory-managed
default 09:09:39.601670+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:39.602798+0100    dasd    Trigger: <private> is now [org.mozilla.firefox]
default 09:09:39.603766+0100    kernel  1 duplicate report for Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:39.603796+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-xattr /Applications/Firefox.app/Contents/MacOS/firefox
default 09:09:39.605701+0100    dasd    Trigger: <private> is now [org.mozilla.firefox]
default 09:09:39.626120+0100    kernel  Sandbox: ContextStoreAgent(759) allow file-read-data /Applications/Firefox.app/Contents/Info.plist
default 09:09:39.633251+0100    firefox networkd_settings_read_from_file initialized networkd settings by reading plist directly
default 09:09:39.633668+0100    firefox networkd_settings_read_from_file initialized networkd settings by reading plist directly
default 09:09:39.635162+0100    firefox nw_path_evaluator_start [66052436-E50B-4169-8CFE-A26C436E6BD0 <NULL> generic, attribution: developer]
    path: satisfied (Path is satisfied), interface: en0[802.11], ipv4, dns, uses wifi
default 09:09:39.635729+0100    firefox [0x102a56d30] activating connection: mach=true listener=false peer=false name=com.apple.SystemConfiguration.DNSConfiguration
default 09:09:39.636636+0100    firefox [0x102a56d30] invalidated after the last release of the connection object
default 09:09:39.672472+0100    runningboardd   Invalidating assertion 215-170-72794 (target:[anon<firefox>(501):29644]) from originator [osservice<com.apple.coreservices.launchservicesd>:170]
default 09:09:39.745053+0100    runningboardd   [anon<firefox>(501):29644] Ignoring jetsam update because this process is not memory-managed
default 09:09:39.745285+0100    runningboardd   [anon<firefox>(501):29644] Ignoring suspend because this process is not lifecycle managed
default 09:09:39.745625+0100    runningboardd   [anon<firefox>(501):29644] Set darwin role to: UserInteractiveNonFocal
default 09:09:39.745863+0100    runningboardd   [anon<firefox>(501):29644] Ignoring GPU update because this process is not GPU managed
default 09:09:39.746414+0100    runningboardd   [anon<firefox>(501):29644] Ignoring memory limit update because this process is not memory-managed
default 09:09:40.021228+0100    kernel  AGC:: [firefox pid:29644 mux-aware] starting, non-mux-aware app count 0 WS-ready 1 switch-state 0 IG FBs 1 EG FBs 0:0 power-state 6 3D idle HDA idle system-state 1 power-level 20:20 power-retry 0:0 connect-change 0
default 09:09:40.063131+0100    distnoted   register name: com.apple.nsquiet_safe_quit_give_reason object: org.mozilla.firefox token: 200000001b pid: 29644
default 09:09:40.070389+0100    firefox [0x111ec9130] activating connection: mach=true listener=false peer=false name=com.apple.windowmanager.server
default 09:09:40.070508+0100    firefox [0x1127f1f10] activating connection: mach=true listener=false peer=false name=com.apple.cvmsServ
default 09:09:40.071394+0100    WindowManager   Connection activated | (29644) Firefox
default 09:09:40.072838+0100    firefox NSApp cache appearance:
-NSRequiresAquaSystemAppearance: 0
-appearance: (null)
-effectiveAppearance: <NSCompositeAppearance: 0x10b038180
 (
    "<NSAquaAppearance: 0x10b038d00>",
    "<NSSystemAppearance: 0x10b038b00>"
)>
default 09:09:40.083549+0100    firefox [0x12b7e76b0] activating connection: mach=true listener=false peer=false name=com.apple.pasteboard.1
default 09:09:40.200776+0100    firefox [0x10b046d00] activating connection: mach=true listener=false peer=false name=com.apple.fonts
default 09:09:40.310240+0100    firefox [0x102a561f0] activating connection: mach=true listener=false peer=false name=com.apple.dock.fullscreen
default 09:09:40.393476+0100    firefox Registering for test daemon availability notify post.
default 09:09:40.393785+0100    firefox notify_get_state check indicated test daemon not ready.
default 09:09:40.394007+0100    firefox notify_get_state check indicated test daemon not ready.
default 09:09:40.394263+0100    firefox notify_get_state check indicated test daemon not ready.
default 09:09:40.400396+0100    firefox [0x12a5d55e0] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.sharedfilelistd.xpc
default 09:09:40.413522+0100    firefox Received DFR status change 0. status = 0x1
default 09:09:40.414839+0100    firefox Received DFR status change 1. status = 0x1
default 09:09:40.416435+0100    firefox [0x102a56010] activating connection: mach=true listener=false peer=false name=com.apple.coreservices.appleevents
default 09:09:40.419146+0100    firefox SignalReady: pid=29644 asn=0x0-0xcc1cc1
default 09:09:40.421358+0100    firefox SIGNAL: pid=29644 asn=0x0x-0xcc1cc1
default 09:09:40.434772+0100    firefox Reacting to DFR status change 0. status = 0x1
default 09:09:40.436120+0100    firefox Reacting to DFR status change 1. status = 0x1
default 09:09:40.437087+0100    loginwindow -[ApplicationManager checkInAppContext:eventData:] | ApplicationManager: Checked in app : FirefoxCP
default 09:09:40.570993+0100    firefox Shortcuts Contextual Actions enabled
default 09:09:40.638808+0100    firefox [0x129245460] activating connection: mach=true listener=false peer=false name=com.apple.sidecar-relay
default 09:09:40.640485+0100    firefox Allow all devices for Sidecar display: [NO]
default 09:09:40.640856+0100    firefox Device is supported: [NO].  Device: [<private>]
default 09:09:40.661309+0100    firefox [0x12a9a3e30] activating connection: mach=true listener=false peer=false name=com.apple.window_proxies
default 09:09:40.661506+0100    firefox [0x12a9a3e30] invalidated on xpc_connection_cancel()
default 09:09:40.713608+0100    firefox void _updateToReflectAutomaticTerminationState(void) Setting _kLSApplicationWouldBeTerminatedByTALKey=1
default 09:09:41.112354+0100    firefox Not internal release, disabling SIRL
default 09:09:41.113698+0100    firefox Enabling System Keychain Always due to platform
default 09:09:41.114495+0100    firefox [0x12a861e30] activating connection: mach=true listener=false peer=false name=com.apple.securityd.xpc
default 09:09:41.114707+0100    firefox Adding securityd connection to pool, total now 1
default 09:09:41.132005+0100    firefox [0x12a904a60] activating connection: mach=false listener=false peer=false name=com.apple.hiservices-xpcservice
default 09:09:41.133702+0100    firefox Recording an MDS plugin: /System/Library/Security/ldapdl.bundle {87191ca6-0fc9-11d4-849a-000502b52122}
default 09:09:41.134612+0100    firefox Recording an MDS plugin: /System/Library/Frameworks/Security.framework {87191ca0-0fc9-11d4-849a-000502b52122}

Indeed it tries to launch firefox now and it tried to start firefox-bin before.

Thank you!

whimboo commented 6 months ago

geckodriver 0.34.0 has been released: https://github.com/mozilla/geckodriver/releases/tag/v0.34.0

lprimak commented 6 months ago

Mine still fails due to https://bugzilla.mozilla.org/show_bug.cgi?id=1872516

whimboo commented 6 months ago

Mine still fails due to https://bugzilla.mozilla.org/show_bug.cgi?id=1872516

Right, but that's unrelated to the fix in geckodriver. And we have to wait until the developer is back before we can make progress on it. So please be patient for some more days. Thanks!

mozilla / geckodriver