Open duncan-bayne opened 1 month ago
@duncan-bayne, thank you for creating this issue. We will troubleshoot it as soon as we can.
Triage this issue by using labels.
If information is missing, add a helpful comment and then I-issue-template
label.
If the issue is a question, add the I-question
label.
If the issue is valid but there is no time to troubleshoot it, consider adding the help wanted
label.
If the issue requires changes or fixes from an external project (e.g., ChromeDriver, GeckoDriver, MSEdgeDriver, W3C),
add the applicable G-*
label, and it will provide the correct link and auto-close the
issue.
After troubleshooting the issue, please add the R-awaiting answer
label.
Thank you!
@duncan-bayne Could you try to set pageLoadStrategy
to eager
and check the script does continue?
If it does continue the browser is unable to load the page before the session-timeout
is hit.
@joerg1985 Afraid it didn't continue after I made the following change to our helper method that builds the Chromedriver options:
# Generates chromedriver options.
# Yields the options instance to the block param, if it's present
def Capybara.generate_chromedriver(app, &blk)
options = Selenium::WebDriver::Chrome::Options.new
options.logging_prefs = {browser: "ALL", performance: "ALL"}
options.perf_logging_prefs = {enable_network: true}
options.page_load_strategy = :eager # <= added
# ... snip ...
It's worth mentioning that some of these failures are happening at points where we do something completely innocuous like visit("about:blank")
.
Does this only happen when calling a URL or are other commands affected?
The pattern is that the error occurs on a visit
or a resize_window_to
, but then subsequent commands (usually save_screenshot
in our after
hook) fail as well. E.g.:
[2024-10-01T03:55:16Z] Failures:
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] 1) viewing a changeset an article with MCQs
[2024-10-01T03:55:16Z] Got 0 failures and 3 other errors:
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] 1.1) Failure/Error: super(*args, **kwargs.except(:skip_waiting_for_load))
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] Selenium::WebDriver::Error::UnknownError:
[2024-10-01T03:55:16Z] Unable to execute request for an existing session: java.util.concurrent.TimeoutException
[2024-10-01T03:55:16Z] Build info: version: '4.20.0', revision: '866c76ca80'
[2024-10-01T03:55:16Z] System info: os.name: 'Linux', os.arch: 'aarch64', os.version: '6.1.106-116.188.amzn2023.aarch64', java.version: '17.0.11'
[2024-10-01T03:55:16Z] Driver info: driver.version: unknown
[2024-10-01T03:55:16Z] # ./spec/support/helpers/test_helpers/capybara_helpers.rb:7:in `visit'
[2024-10-01T03:55:16Z] # ./spec/features/changesets/show_spec.rb:76:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:135:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:134:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/good_job.rb:7:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/database_cleaner.rb:19:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:177:in `block (4 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./app/lib/tiny_otel.rb:86:in `in_span'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:176:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:163:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ------------------
[2024-10-01T03:55:16Z] # --- Caused by: ---
[2024-10-01T03:55:16Z] # Selenium::WebDriver::Error::WebDriverError:
[2024-10-01T03:55:16Z] # java.lang.RuntimeException: Unable to execute request for an existing session: java.util.concurrent.TimeoutException
[2024-10-01T03:55:16Z] Build info: version: '4.20.0', revision: '866c76ca80'
[2024-10-01T03:55:16Z] System info: os.name: 'Linux', os.arch: 'aarch64', os.version: '6.1.106-116.188.amzn2023.aarch64', java.version: '17.0.11'
[2024-10-01T03:55:16Z] Driver info: driver.version: unknown
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:208)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:383)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.router.Router.execute(Router.java:87)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
[2024-10-01T03:55:16Z] at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[2024-10-01T03:55:16Z] at java.base/java.lang.Thread.run(Unknown Source)
[2024-10-01T03:55:16Z] Caused by: java.util.concurrent.TimeoutException
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.CompletableFuture.timedGet(Unknown Source)
[2024-10-01T03:55:16Z] at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:379)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:352)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:54)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.node.DefaultActiveSession.execute(DefaultActiveSession.java:62)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:126)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:628)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:383)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:87)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:346)
[2024-10-01T03:55:16Z] at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.node.Node.execute(Node.java:262)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.web.CombinedHandler.execute(CombinedHandler.java:55)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.web.RoutableHttpClientFactory$1.execute(RoutableHttpClientFactory.java:71)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)
[2024-10-01T03:55:16Z] at org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:181)
[2024-10-01T03:55:16Z] ... 30 more
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] 1.2) Failure/Error: path = save_screenshot(example.description.first(60) + ".png", full_page: false) # Chromedriver always takes a full page screenshot, but errors if you ask it to do so.
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] Selenium::WebDriver::Error::ServerError:
[2024-10-01T03:55:16Z] status code 404; payload {"value"=>"/session/5ce5484ad358bf2f0339e748a2293a21/screenshot", "message"=>"Unable to route (GET) /session/5ce5484ad358bf2f0339e748a2293a21/screenshot", "error"=>"org.openqa.selenium.UnsupportedCommandException"}
[2024-10-01T03:55:16Z] # ./spec/support/database_cleaner.rb:49:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:135:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:134:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/good_job.rb:7:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/database_cleaner.rb:19:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:177:in `block (4 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./app/lib/tiny_otel.rb:86:in `in_span'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:176:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:163:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] 1.3) Failure/Error: example.run
[2024-10-01T03:55:16Z]
[2024-10-01T03:55:16Z] Selenium::WebDriver::Error::ServerError:
[2024-10-01T03:55:16Z] status code 404; payload {"value"=>"/session/5ce5484ad358bf2f0339e748a2293a21/cookie", "message"=>"Unable to route (DELETE) /session/5ce5484ad358bf2f0339e748a2293a21/cookie", "error"=>"org.openqa.selenium.UnsupportedCommandException"}
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:135:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/rails_helper.rb:134:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/good_job.rb:7:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/support/database_cleaner.rb:19:in `block (2 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:177:in `block (4 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./app/lib/tiny_otel.rb:86:in `in_span'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:176:in `block (3 levels) in <top (required)>'
[2024-10-01T03:55:16Z] # ./spec/spec_helper.rb:163:in `block (2 levels) in <top (required)>'
What happened?
Firstly, thanks for Selenium :pray: We've been using it for 15 years, and have built a large and useful automated test suite with it :heart:
Recently we've been seeing intermittent session errors, in tests that have run (in some cases for years) without issues. These happen at various times in the test lifecycle, from
before(:each)
toafter(:suite)
. They take the form:Retrying the test will often cause it to pass.
We tried reproducing the failures locally. This was unsuccessful; the failures only happen in CI (running through Buildkite, inside Docker containers).
We then took the following steps to try to eliminate other causes of the intermittent failures. All were unsuccessful.
selenium-webdriver
Gem to the very latest version (4.25.0).We also tested switching from Selenium to Cuprite; when running under Cuprite, the tests worked reliably, which led us to believe the issue lies with Selenium.
How can we reproduce the issue?
We can't reproduce this outside the context of our CI system; however the debugging steps above lead me to believe it's an issue with Selenium.
If debugging on our stack could help resolve the issue, I'm very happy to look into how we might make that possible.
Relevant log output
When running Chrome in its own container via a remote browser connection, this is what we see in the logs when one of these failures occur:
When running Chromium locally on the test container, we see the following error:
Operating System
Ubuntu 22.04 LTS
Selenium version
Ruby 3.3.5
What are the browser(s) and version(s) where you see this issue?
Chrome 124, Chrome 117, Firefox 130.
What are the browser driver(s) and version(s) where you see this issue?
ChromeDriver 124.0.6367.78 (and others; see above for attempts to resolve the issue).
Are you using Selenium Grid?
No.