cimg-ruby icon indicating copy to clipboard operation
cimg-ruby copied to clipboard

Published 20 hours ago • verified publisher icon CircleCI-Public

Bug Report: lots of build flake with Firefox via `-browsers`

Open mockdeep opened this issue 6 months ago • 0 comments
trafficstars

Describe the bug

For the past month or so, we've been getting a lot more build flake in our CI builds when using Selenium with Firefox. You can see an example in this build on an open source project. It complains about "Process unexpectedly closed with status 1" and every subsequent test fails. I enabled selenium logging for a bit more detail and got the following. In particular, the error "Error: cannot open display: :99" seems to suggest that the display is not available for some reason.

Selenium Logs 
# Logfile created on 2025-04-20 12:24:54 -0700 by logger.rb/v1.7.0
2025-04-20 12:24:55 INFO Selenium [:logger_info] Details on how to use and modify Selenium logger:
  https://selenium.dev/documentation/webdriver/troubleshooting/logging

2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Selenium Manager binary found at /home/circleci/app/vendor/bundle/ruby/3.4.0/gems/selenium-webdriver-4.31.0/bin/linux/selenium-manager 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Executing Process ["/home/circleci/app/vendor/bundle/ruby/3.4.0/gems/selenium-webdriver-4.31.0/bin/linux/selenium-manager", "--browser", "firefox", "--language-binding", "ruby", "--output", "json", "--debug"] 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Sending stats to Plausible: Props { browser: "firefox", browser_version: "", os: "linux", arch: "x86_64", lang: "ruby", selenium_version: "4.31" } 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] geckodriver not found in PATH 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] firefox detected at /usr/bin/firefox 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Running command: /usr/bin/firefox -v 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Output: "Mozilla Firefox 135.0" 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Detected browser: firefox 135.0 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Valid geckodriver versions for firefox 135: ["0.36.0", "0.35.0", "0.34.0"] 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Required driver: geckodriver 0.36.0 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] geckodriver 0.36.0 already in the cache 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Driver path: /home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Browser path: /usr/bin/firefox 
2025-04-20 12:24:55 DEBUG Selenium [:driver_service] Executing Process ["/home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver", "--port=4444"] 
2025-04-20 12:24:55 DEBUG Selenium [:process] Starting process: ["/home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver", "--port=4444"] with {[:out, :err] => #<File:/home/circleci/app/log/selenium.log>, pgroup: true} 
2025-04-20 12:24:55 DEBUG Selenium [:process]   -> pid: 403 
2025-04-20 12:24:55 DEBUG Selenium [:driver_service] polling for socket on ["127.0.0.1", 4444] 
1745177095549	geckodriver	INFO	Listening on 127.0.0.1:4444
2025-04-20 12:24:55 DEBUG Selenium [:command] -> POST session 
2025-04-20 12:24:55 DEBUG Selenium [:command]    >>> http://127.0.0.1:4444/session | {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{"binary":"/usr/bin/firefox","log":{"level":"trace"},"prefs":{"remote.active-protocols":3,"browser.download.folderList":2,"browser.download.manager.showWhenStarting":false,"browser.download.dir":"/home/circleci/app/tmp/downloads","browser.helperApps.neverAsk.saveToDisk":"text/csv"}},"moz:debuggerAddress":true}}} 
2025-04-20 12:24:55 DEBUG Selenium [:header]      > {"Accept" => "application/json", "Content-Type" => "application/json; charset=UTF-8", "User-Agent" => "selenium/4.31.0 (ruby linux)", "Content-Length" => "417"} 
1745177095805	mozrunner::runner	INFO	Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" "/usr/bin/firefox" "--m ... tte" "--remote-debugging-port" "9222" "--remote-allow-hosts" "localhost" "-no-remote" "-profile" "/tmp/rust_mozprofileDULmct"
1745177095806	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
1745177095806	geckodriver::browser	TRACE	Failed to open /tmp/rust_mozprofileDULmct/MarionetteActivePort
1745177095806	geckodriver::marionette	TRACE	Retrying in 100ms
Error: cannot open display: :99
1745177095906	geckodriver::browser	DEBUG	Browser process stopped: exit status: 1
1745177095906	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status 1","stacktrace":""}}
2025-04-20 12:24:55 DEBUG Selenium [:header]    <<<  {"content-type" => ["application/json; charset=utf-8"], "cache-control" => ["no-cache"], "content-length" => ["105"], "date" => ["Sun, 20 Apr 2025 19:24:55 GMT"]} 
2025-04-20 12:24:55 DEBUG Selenium [:command] <- {"value":{"error":"unknown error","message":"Process unexpectedly closed with status 1","stacktrace":""}} 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Executing Process ["/home/circleci/app/vendor/bundle/ruby/3.4.0/gems/selenium-webdriver-4.31.0/bin/linux/selenium-manager", "--browser", "firefox", "--browser-path", "/usr/bin/firefox", "--language-binding", "ruby", "--output", "json", "--debug"] 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] geckodriver not found in PATH 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Running command: /usr/bin/firefox -v 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Output: "Mozilla Firefox 135.0" 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Detected browser: firefox 135.0 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Required driver: geckodriver 0.36.0 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] geckodriver 0.36.0 already in the cache 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Driver path: /home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver 
2025-04-20 12:24:55 DEBUG Selenium [:selenium_manager] Browser path: /usr/bin/firefox 
2025-04-20 12:24:55 DEBUG Selenium [:driver_service] Executing Process ["/home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver", "--port=4445"] 
2025-04-20 12:24:55 DEBUG Selenium [:process] Starting process: ["/home/circleci/.cache/selenium/geckodriver/linux64/0.36.0/geckodriver", "--port=4445"] with {[:out, :err] => #<File:/home/circleci/app/log/selenium.log>, pgroup: true} 
2025-04-20 12:24:55 DEBUG Selenium [:process]   -> pid: 445 
2025-04-20 12:24:55 DEBUG Selenium [:driver_service] polling for socket on ["127.0.0.1", 4445] 
1745177095956	geckodriver	INFO	Listening on 127.0.0.1:4445
2025-04-20 12:24:56 DEBUG Selenium [:command] -> POST session 
2025-04-20 12:24:56 DEBUG Selenium [:command]    >>> http://127.0.0.1:4445/session | {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{"binary":"/usr/bin/firefox","log":{"level":"trace"},"prefs":{"remote.active-protocols":3,"browser.download.folderList":2,"browser.download.manager.showWhenStarting":false,"browser.download.dir":"/home/circleci/app/tmp/downloads","browser.helperApps.neverAsk.saveToDisk":"text/csv"}},"moz:debuggerAddress":true}}} 
2025-04-20 12:24:56 DEBUG Selenium [:header]      > {"Accept" => "application/json", "Content-Type" => "application/json; charset=UTF-8", "User-Agent" => "selenium/4.31.0 (ruby linux)", "Content-Length" => "417"} 
1745177096206	webdriver::server	DEBUG	-> POST /session {"capabilities":{"alwaysMatch":{"acceptInsecureCerts":true,"browserName":"firefox","moz:firefoxOptions":{"bi ... d.dir":"/home/circleci/app/tmp/downloads","browser.helperApps.neverAsk.saveToDisk":"text/csv"}},"moz:debuggerAddress":true}}}
1745177096206	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
1745177096207	geckodriver::capabilities	DEBUG	Found version 135.0
1745177096209	mozrunner::runner	INFO	Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" "/usr/bin/firefox" "--m ... tte" "--remote-debugging-port" "9222" "--remote-allow-hosts" "localhost" "-no-remote" "-profile" "/tmp/rust_mozprofilegTVn1h"
1745177096209	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1
1745177096209	geckodriver::browser	TRACE	Failed to open /tmp/rust_mozprofilegTVn1h/MarionetteActivePort
1745177096209	geckodriver::marionette	TRACE	Retrying in 100ms
Error: cannot open display: :99
1745177096309	geckodriver::browser	DEBUG	Browser process stopped: exit status: 1
1745177096310	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"unknown error","message":"Process unexpectedly closed with status 1","stacktrace":""}}
2025-04-20 12:24:56 DEBUG Selenium [:header]    <<<  {"content-type" => ["application/json; charset=utf-8"], "cache-control" => ["no-cache"], "content-length" => ["105"], "date" => ["Sun, 20 Apr 2025 19:24:55 GMT"]} 
2025-04-20 12:24:56 DEBUG Selenium [:command] <- {"value":{"error":"unknown error","message":"Process unexpectedly closed with status 1","stacktrace":""}} 
2025-04-20 12:24:56 DEBUG Selenium [:selenium_manager] Executing Process ["/home/circleci/app/vendor/bundle/ruby/3.4.0/gems/selenium-webdriver-4.31.0/bin/linux/selenium-manager", "--browser", "firefox", "--browser-path", "/usr/bin/firefox", "--language-binding", "ruby", "--output", "json", "--debug"] 
...

To Reproduce

This appears to happen with pretty much any Firefox/Selenium build on the Ruby image with -browsers, at least for me. You can check out this PR for a starting place.

Expected behavior

geckodriver should be able to reliably connect to the virtual display.

Workarounds

Right now we just end up re-running builds until they succeed, which is a pain.

mockdeep avatar Apr 22 '25 16:04 mockdeep