BUG: Selenium::WebDriver::Error::TimeoutError

[mockdeep]

Describe the bug

We occasionally get test flake on CI with Selenium::WebDriver::Error::TimeoutError. It looks like Selenium is timing out when trying to get about:blank inside within_about_blank_context. I'm going to see if I can increase the timeout, since right now it's only 1 second, but I'm wondering if this is something that should be handled somehow inside of the gem.

Environment Happening In

• Production
• QA
• Dev

To Reproduce

I don't have a great way to reproduce it, unfortunately. Basically, you need to run it lots of times on CI (we run it on every button or link click). One thing to note is that it only seems to happen very early in the test, like on the login page. We do have assertions to ensure that our page is fully loaded before running be_axe_clean. Here is the error and stack trace:

     1.1) Failure/Error: expect(page).to be_axe_clean.skipping(*a11y_skip)
          
          Selenium::WebDriver::Error::TimeoutError:
            Navigation timed out after 1000 ms
          # RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
          # WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:189:5
          # TimeoutError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:691:5
          # bail@chrome://remote/content/marionette/sync.sys.mjs:211:19
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/response.rb:55:in `assert_ok'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/response.rb:34:in `initialize'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/http/common.rb:83:in `new'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/http/common.rb:83:in `create_response'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/http/default.rb:103:in `request'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/http/common.rb:59:in `call'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/bridge.rb:607:in `execute'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/remote/bridge.rb:96:in `get'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/common/navigation.rb:32:in `to'
          # ./vendor/bundle/ruby/3.3.0/gems/selenium-webdriver-4.19.0/lib/selenium/webdriver/common/driver.rb:135:in `get'
          # ./vendor/bundle/ruby/3.3.0/gems/axe-core-api-4.9.0/lib/axe/api/run.rb:101:in `within_about_blank_context'
          # ./vendor/bundle/ruby/3.3.0/gems/axe-core-api-4.9.0/lib/axe/api/run.rb:41:in `analyze_post_43x'
          # ./vendor/bundle/ruby/3.3.0/gems/axe-core-api-4.9.0/lib/axe/core.rb:19:in `call'
          # ./vendor/bundle/ruby/3.3.0/gems/axe-core-api-4.9.0/lib/axe/matchers/be_axe_clean.rb:22:in `audit'
          # ./vendor/bundle/ruby/3.3.0/gems/axe-core-api-4.9.0/lib/axe/matchers/be_axe_clean.rb:26:in `matches?'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:51:in `block in handle_matcher'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:27:in `with_matcher'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:48:in `handle_matcher'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/expectation_target.rb:65:in `to'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/expectation_target.rb:101:in `to'
          # ./spec/support/accessibility_overrides.rb:89:in `block in check_axe'
          # ./vendor/bundle/ruby/3.3.0/gems/capybara-3.40.0/lib/capybara/session.rb:559:in `within_window'
          # ./vendor/bundle/ruby/3.3.0/gems/capybara-screenshot-1.0.26/lib/capybara-screenshot/capybara.rb:33:in `within_window'
          # ./vendor/bundle/ruby/3.3.0/gems/capybara-3.40.0/lib/capybara/dsl.rb:52:in `call'
          # ./vendor/bundle/ruby/3.3.0/gems/capybara-3.40.0/lib/capybara/dsl.rb:52:in `within_window'
          # ./spec/support/accessibility_overrides.rb:87:in `check_axe'
          # ./spec/support/accessibility_overrides.rb:79:in `check_accessibility'
          # ./spec/support/accessibility_overrides.rb:72:in `check_browser_errors'
          # ./spec/support/accessibility_overrides.rb:22:in `click_on'
          # ./spec/features/_flows/global_flow.rb:16:in `user_fills_login_info'
          # ./spec/features/_flows/global_flow.rb:8:in `user_logs_in_as'
          # ./spec/features/doc_setup/field_management/auto_detect_fields_spec.rb:10:in `block (2 levels) in <top (required)>'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:365:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:529:in `block in run_owned_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:528:in `each'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:528:in `run_owned_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:615:in `block in run_example_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:614:in `reverse_each'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:614:in `run_example_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:484:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:505:in `run_before_example'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:261:in `block in run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:511:in `block in with_around_and_singleton_context_hooks'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:468:in `block in with_around_example_hooks'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:486:in `block in run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:626:in `block in run_around_example_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:352:in `call'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-rails-6.1.2/lib/rspec/rails/adapters.rb:75:in `block (2 levels) in <module:MinitestLifecycleAdapter>'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:390:in `execute_with'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:352:in `call'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:629:in `run_around_example_hooks_for'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:486:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:468:in `with_around_example_hooks'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:511:in `with_around_and_singleton_context_hooks'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:259:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:646:in `block in run_examples'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:642:in `map'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:642:in `run_examples'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:607:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `block (3 levels) in run_specs'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `map'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `block (2 levels) in run_specs'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/configuration.rb:2091:in `with_suite_hooks'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:116:in `block in run_specs'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/reporter.rb:74:in `report'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:115:in `run_specs'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:89:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:71:in `run'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:45:in `invoke'
          # ./vendor/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/exe/rspec:4:in `<top (required)>'
          # ./vendor/bundle/ruby/3.3.0/bin/rspec:25:in `load'
          # ./vendor/bundle/ruby/3.3.0/bin/rspec:25:in `<top (required)>'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `load'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `kernel_load'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:23:in `run'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli.rb:486:in `exec'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli.rb:31:in `dispatch'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/cli.rb:25:in `start'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/exe/bundle:48:in `block in <top (required)>'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/lib/bundler/friendly_errors.rb:120:in `with_friendly_errors'
          # /home/circleci/.rubygems/gems/bundler-2.3.25/exe/bundle:36:in `<top (required)>'
          # /home/circleci/.rubygems/bin/bundle:25:in `load'
          # /home/circleci/.rubygems/bin/bundle:25:in `<main>'

Expected behavior

Consistently executing accessibility checks.

Actual behavior

Something like 5-10% of builds fail due to one of the tests getting this timeout.

Screenshots

n/a

Related Tickets

n/a

Desktop:

• Product: selenium-webdriver
• Product Version: 4.19.0
• OS: Ubuntu Linux
• Browser: Firefox
• Browser Version: 121

[mockdeep]

Okay, I was trying to figure out where that "1000 ms" was coming from, and realized you set it inside your code. So I can't really control that. Not sure if it will do any good, but I might try navigating to a blank page at the beginning of each test to make sure about:blank can load quickly.

[mockdeep]

Welp, that didn't work either. It looks like the timeout was added in #315, but it's not clear to me why it was needed.

[mockdeep]

Following up on this. I put an ugly hack in our code to prevent axe-core from changing the timeout, and we haven't seen one of these errors in nearly a month.

  config.before(:each, type: :system) do
    page.driver.browser.manage.timeouts.instance_eval do
      def page_load=(*)
        # no-op don't want axe-core changing this
      end
    end
  end

@AdnoC looks like you introduced the timeout. Do you have any suggestions on how to proceed with this?

[micha-lieber]

We encountered the same problem (getting flaky CI tests where we use be_axe_clean, resulting in Selenium::WebDriver::Error::TimeoutError) with our feature specs and @mockdeep s solution worked (thank you!), but, as mentioned by them, did not feel very good 🙂 our current work-around is, to not use the be_axe_clean matcher directly after a page reload, but rather after another expectation. This also feels less than optimal, but works for now 🤷

[mockdeep]

For what it's worth, we still run our axe checks after an assertion to ensure that the page is fully loaded. I'm not sure if there's a way for axe-core to automatically detect that the page is settled. I suppose it could at least check that the page is fully loaded, but it would still have a hard time detecting whether there is any other JavaScript behavior on the page.

At any rate, we still see this issue, even with an assertion to ensure that the page is fully loaded.