titusfortner / webdrivers

Keep your Selenium WebDrivers updated automatically
MIT License
592 stars 113 forks source link

Non-deterministic failures running `chromedriver --version` in Github Actions #245

Closed machty closed 1 year ago

machty commented 1 year ago

Summary

In the past few weeks I've noticed an uptick in Github Action job failures due to attempting to download chromedriver but failing when chromedriver --version runs.

Debug Info

Please provide the following information for bug reports:

Expected Behavior

It doesn't fail

Actual Behavior

There's a 15% chance that a job in my test matrix that does browser specs will fail to install chromedriver.

There actually seems to be a few different kinds of failures that occur:

  1. Generic "Failed to make system call"
Ruby YJIT Enabled: true
2023-03-06 17:15:23 DEBUG Webdrivers Checking current version
2023-03-06 17:15:23 DEBUG Webdrivers /home/runner/work/business-server/business-server/tmp/chromedriver is not already downloaded
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers Checking current version
2023-03-06 17:15:23 DEBUG Webdrivers /home/runner/work/business-server/business-server/tmp/chromedriver is not already downloaded
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers Making network call to https://chromedriver.storage.googleapis.com/LATEST_RELEASE_110.0.5481
2023-03-06 17:15:23 DEBUG Webdrivers Get response: #<Net::HTTPOK 200 OK readbody=true>
2023-03-06 17:15:23 DEBUG Webdrivers Latest version available: 110.0.5481.77
2023-03-06 17:15:23 DEBUG Webdrivers Deleting /home/runner/work/business-server/business-server/tmp/chromedriver.version
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers Checking current version
2023-03-06 17:15:23 DEBUG Webdrivers /home/runner/work/business-server/business-server/tmp/chromedriver is not already downloaded
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/usr/bin/google-chrome", "--product-version"]
2023-03-06 17:15:23 DEBUG Webdrivers System call returned: 110.0.5481.177

2023-03-06 17:15:23 DEBUG Webdrivers Browser version: 110.0.5481.177
2023-03-06 17:15:23 DEBUG Webdrivers Making network call to https://chromedriver.storage.googleapis.com/LATEST_RELEASE_110.0.5481
2023-03-06 17:15:23 DEBUG Webdrivers Get response: #<Net::HTTPOK 200 OK readbody=true>
2023-03-06 17:15:23 DEBUG Webdrivers Latest version available: 110.0.5481.77
2023-03-06 17:15:23 DEBUG Webdrivers chromedriver URL: https://chromedriver.storage.googleapis.com/110.0.5481.77/chromedriver_linux64.zip
2023-03-06 17:15:23 DEBUG Webdrivers Making network call to https://chromedriver.storage.googleapis.com/110.0.5481.77/chromedriver_linux64.zip
2023-03-06 17:15:23 DEBUG Webdrivers Get response: #<Net::HTTPOK 200 OK readbody=true>
2023-03-06 17:15:23 DEBUG Webdrivers Successfully downloaded /tmp/20230306-2837-8[45](https://github.com/FutureProofRetail/business-server/actions/runs/4346062033/jobs/7591643043#step:18:46)alechromedriver_linux64.zip
2023-03-06 17:15:23 DEBUG Webdrivers Decompressing /tmp/20230306-2837-845alechromedriver_linux64.zip
2023-03-06 17:15:23 DEBUG Webdrivers Completed download and processing of /home/runner/work/business-server/business-server/tmp/chromedriver
2023-03-06 17:15:23 DEBUG Webdrivers Checking current version
2023-03-06 17:15:23 DEBUG Webdrivers /home/runner/work/business-server/business-server/tmp/chromedriver is already downloaded
2023-03-06 17:15:23 DEBUG Webdrivers making System call: ["/home/runner/work/business-server/business-server/tmp/chromedriver", "--version"]
rails aborted!
Failed to make system call: ["/home/runner/work/business-server/business-server/tmp/chromedriver", "--version"]
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/system.rb:190:in `call'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/common.rb:1[48](https://github.com/FutureProofRetail/business-server/actions/runs/4346062033/jobs/7591643043#step:18:49):in `binary_version'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/chromedriver.rb:18:in `current_version'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/tasks/chromedriver.rake:24:in `block (3 levels) in <top (required)>'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/bugsnag-6.24.2/lib/bugsnag/integrations/rake.rb:20:in `execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
/home/runner/work/business-server/business-server/Rakefile:22:in `block in <top (required)>'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/bugsnag-6.24.2/lib/bugsnag/integrations/rake.rb:20:in `execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:160:in `invoke_task'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block (2 levels) in top_level'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `each'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block in top_level'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:125:in `run_with_threads'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:110:in `top_level'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/railties-6.1.4.7/lib/rails/commands/rake/rake_command.rb:24:in `block (2 levels) in perform'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/railties-6.1.4.7/lib/rails/commands/rake/rake_command.rb:24:in `block in perform'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/rake_module.rb:59:in `with_application'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/railties-6.1.4.7/lib/rails/commands/rake/rake_command.rb:18:in `perform'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/railties-6.1.4.7/lib/rails/command.rb:[50](https://github.com/FutureProofRetail/business-server/actions/runs/4346062033/jobs/7591643043#step:18:51):in `invoke'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/railties-6.1.4.7/lib/rails/commands.rb:18:in `<top (required)>'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/bootsnap-1.10.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/bootsnap-1.10.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
Tasks: TOP => webdrivers:chromedriver:update
  1. Inconsistency detected by ld.so (omitted duplicate logs from above, which share similar prelude)

2023-03-06 17:43:25 DEBUG Webdrivers Completed download and processing of /home/runner/work/business-server/business-server/tmp/chromedriver
2023-03-06 17:43:25 DEBUG Webdrivers Checking current version
2023-03-06 17:43:25 DEBUG Webdrivers /home/runner/work/business-server/business-server/tmp/chromedriver is already downloaded
2023-03-06 17:43:25 DEBUG Webdrivers making System call: ["/home/runner/work/business-server/business-server/tmp/chromedriver", "--version"]
Inconsistency detected by ld.so: dl-version.c: 204: _dl_check_map_versions: Assertion `needed != NULL' failed!
rails aborted!
Failed to make system call: ["/home/runner/work/business-server/business-server/tmp/chromedriver", "--version"]
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/system.rb:190:in `call'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/common.rb:148:in `binary_version'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/chromedriver.rb:18:in `current_version'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/webdrivers-5.2.0/lib/webdrivers/tasks/chromedriver.rake:24:in `block (3 levels) in <top (required)>'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
/home/runner/work/business-server/business-server/vendor/bundle/ruby/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
  1. Decompression failure -- this one fails earlier, when attempting to decompress
2023-03-06 17:42:48 DEBUG Webdrivers Get response: #<Net::HTTPOK 200 OK readbody=true>
2023-03-06 17:42:48 DEBUG Webdrivers Successfully downloaded /tmp/20230306-2881-1479kvchromedriver_linux64.zip
2023-03-06 17:42:48 DEBUG Webdrivers Decompressing /tmp/20230306-2881-1479kvchromedriver_linux64.zip
rails aborted!
Zip::EntrySizeError: entry 'chromedriver' should be 14452880B, but is larger when inflated.
machty commented 1 year ago

I believe I've narrowed it down to an issue within rubyzip when running with Ruby 3.1's YJIT enabled. Tracking here: https://github.com/rubyzip/rubyzip/pull/550

maximecb commented 1 year ago

I believe I've narrowed it down to an issue within rubyzip when running with Ruby 3.1's YJIT enabled. Tracking here: rubyzip/rubyzip#550

Hi @machty. There is an issue with rubyzip that's been reported here: https://github.com/Shopify/yjit/issues/310

We're planning to look at it tomorrow, but if you're somehow able to find an even smaller repro, that would be useful.

With some luck, we'll have this bug fixed this week.

titusfortner commented 1 year ago

That command is looking for a driver on PATH. This gem doesn't put the driver on PATH, it downloads the latest and tells Selenium where to look for it. If you want to see what this gem downloads you can ~/.webdrivers/chromedriver --version

titusfortner commented 1 year ago

Closing as it appears the root issue is with rubyzip.

Another note — if you are using a recent version of Selenium you may not even need to use this gem any longer: https://github.com/titusfortner/webdrivers#update-selenium-manager