Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[🐛 Bug]: Setting chrome to w3c: false in Selenium 4 causes errors #10448

Closed
marcoadkins opened this issue Mar 15, 2022 · 19 comments
Closed

[🐛 Bug]: Setting chrome to w3c: false in Selenium 4 causes errors #10448

marcoadkins opened this issue Mar 15, 2022 · 19 comments
Labels
help wanted Issues looking for contributions I-defect

Comments

@marcoadkins
Copy link

marcoadkins commented Mar 15, 2022

What happened?

Upon upgrading from selenium 3.142 to 4.1, the driver started throwing a Selenium::WebDriver::Error::ScriptTimeoutError when attempting to reset between tests via driver.reset!

How can we reproduce the issue?

No specific details to reproduce. I can provide our configuration though that might be able to help replicate the problem.


# Driver setup
Capybara.register_driver :selenium_chrome_headless do |app|
  capabilities = Selenium::WebDriver::Remote::Capabilities.chrome(
    acceptInsecureCerts: true,
    'goog:chromeOptions': {
      args: %W[
        headless
        proxy-server=#{ENV['CI'] ? 'localhost' : ENV.fetch('NGINX_IP')}:#{Billy.proxy.port}
        window-size=1440,900
      ],
      prefs: {
        download: {
          default_directory: DownloadSpecHelpers::CHROME_PATH
        }
      },
      w3c: false
    },
    'goog:loggingPrefs': {
      browser: 'ALL'
    }
  )

  options = {
    browser: ENV['CI'] ? :chrome : :remote,
    capabilities: capabilities,
    url: 'http://localhost:4445/wd/hub'
  }

  Capybara::Selenium::Driver.new(app, options).tap do |d|
    unless ENV['CI']
      d.browser.file_detector = lambda do |args|
        str = args.first.to_s
        str if File.exist?(str)
      end
    end
  end
end

Relevant log output

Example Failure:
(byebug) Capybara.current_session.driver.reset!
*** Selenium::WebDriver::Error::ScriptTimeoutError Exception: Unable to execute request for an existing session: POST /session/9c2e8f72783418513a46e4354f9fd08f/goog/cdp/execute
Build info: version: '4.1.0', revision: '87802e897b'
System info: host: 'c202f6697df7', ip: '172.18.0.11', os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.47-linuxkit', java.version: '11.0.11'
Driver info: driver.version: unknown


Deeper Stacktrace triggered in rspec run:
     1.1) Failure/Error: Capybara.reset! unless example.exception (rails_helper.rb:89)

          Selenium::WebDriver::Error::ScriptTimeoutError:
            Unable to execute request for an existing session: POST /session/71459489cd31d6928048675764dc467b/goog/cdp/execute
            Build info: version: '4.1.0', revision: '87802e897b'
            System info: host: 'c202f6697df7', ip: '172.18.0.11', os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.47-linuxkit', java.version: '11.0.11'
            Driver info: driver.version: unknown
          # java.lang.RuntimeException: Unable to execute request for an existing session: POST /session/71459489cd31d6928048675764dc467b/goog/cdp/execute
          # Build info: version: '4.1.0', revision: '87802e897b'
          # System info: host: 'c202f6697df7', ip: '172.18.0.11', os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.47-linuxkit', java.version: '11.0.11'
          # Driver info: driver.version: unknown
          # 	at org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:139)
          # 	at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.grid.router.Router.execute(Router.java:91)
          # 	at org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)
          # 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
          # 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
          # 	at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
          # 	at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
          # 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
          # 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
          # 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
          # 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
          # 	at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
          # 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
          # 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
          # 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
          # 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
          # 	at java.base/java.lang.Thread.run(Thread.java:829)
          # ./spec/rails_helper.rb:200:in `block (2 levels) in <top (required)>'

Relevant Selenium Logger Output:

2022-03-16 09:49:28 INFO Selenium -> POST session/bb0994cc75b38f0e33f96c2620f47680/url
2022-03-16 09:49:28 INFO Selenium    >>> http://localhost:4445/wd/hub/session/bb0994cc75b38f0e33f96c2620f47680/url | {"url":"about:blank"}
2022-03-16 09:49:28 INFO Selenium <- {
  "value": null
}
2022-03-16 09:49:28 INFO Selenium -> POST session/bb0994cc75b38f0e33f96c2620f47680/elements
2022-03-16 09:49:28 INFO Selenium    >>> http://localhost:4445/wd/hub/session/bb0994cc75b38f0e33f96c2620f47680/elements | {"using":"xpath","value":"/html/body/*"}
2022-03-16 09:49:28 INFO Selenium <- {
  "value": [
  ]
}
2022-03-16 09:49:28 INFO Selenium -> POST session/bb0994cc75b38f0e33f96c2620f47680/goog/cdp/execute
2022-03-16 09:49:28 INFO Selenium    >>> http://localhost:4445/wd/hub/session/bb0994cc75b38f0e33f96c2620f47680/goog/cdp/execute | {"cmd":"Storage.clearDataForOrigin","params":{"origin":"*","storageTypes":"cookies,local_storage"}}
2022-03-16 09:49:28 INFO Selenium <- {
  "value": {
    "error": "script timeout",
    "message": "Unable to execute request for an existing session: POST \u002fsession\u002fbb0994cc75b38f0e33f96c2620f47680\u002fgoog\u002fcdp\u002fexecute\nBuild info: version: '4.1.0', revision: '87802e897b'\nSystem info: host: '4b975b71dd55', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.47-linuxkit', java.version: '11.0.11'\nDriver info: driver.version: unknown",
    "stacktrace": "java.lang.RuntimeException: Unable to execute request for an existing session: POST \u002fsession\u002fbb0994cc75b38f0e33f96c2620f47680\u002fgoog\u002fcdp\u002fexecute\nBuild info: version: '4.1.0', revision: '87802e897b'\nSystem info: host: '4b975b71dd55', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.47-linuxkit', java.version: '11.0.11'\nDriver info: driver.version: unknown\n\tat org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:139)\n\tat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.grid.router.Router.execute(Router.java:91)\n\tat org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:68)\n\tat org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)\n\tat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)\n\tat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)\n\tat org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)\n\tat java.base\u002fjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)\n\tat java.base\u002fjava.util.concurrent.FutureTask.run(FutureTask.java:264)\n\tat java.base\u002fjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base\u002fjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat java.base\u002fjava.lang.Thread.run(Thread.java:829)\n"
  }
}

Operating System

macOS Big Sur

Selenium version

4.1.0

What are the browser(s) and version(s) where you see this issue?

Google Chrome 96.0.4664.93

What are the browser driver(s) and version(s) where you see this issue?

Google Chrome 96.0.4664.93

Are you using Selenium Grid?

No response

@github-actions
Copy link

@marcoadkins, thank you for creating this issue. We will troubleshoot it as soon as we can.


Info for maintainers

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, 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!

@titusfortner
Copy link
Member

You can turn on logging to see what is getting sent to the driver in what order (Selenium::WebDriver.logger.level = :info)

but this needs to be raised with Capybara https://github.com/teamcapybara/capybara/issues

For some reason #reset! is calling the devtools execute endpoint, and I'm not sure why it would do that.

@marcoadkins
Copy link
Author

@titusfortner Thanks for giving it a look. Alright I'll try the logging and raise the issue with capybara.

@marcoadkins
Copy link
Author

@titusfortner Updated the issue description with the relevant selenium logger output. Looks like Capybara is trying to clear cookies and local storage when it hits the execute endpoint.

@titusfortner
Copy link
Member

Hmm, there is a JS blob that we script for clearing local storage, but it shouldn't be getting sent to goog/cdp/execute

Can you show me the relevant portion of the logs?

@marcoadkins
Copy link
Author

@titusfortner Its in the description. Check the "Relevant Selenium Logger Output:" section.

@marcoadkins
Copy link
Author

@titusfortner It may be due to the fact that my WebDriver is remote. Looking at the remote driver code it calls execute to send the delete cookies command.

#selenium/webdriver/remote/bridge.rb:364

def delete_all_cookies
  execute :delete_all_cookies
end

@titusfortner
Copy link
Member

No, it's coming from this — https://github.com/teamcapybara/capybara/blob/f7ab0b5cd5da86185816c2d5c30d58145fe654ed/lib/capybara/selenium/driver_specializations/chrome_driver.rb#L54

Selenium isn't actually doing anything more than sending that code along to the driver, so if there's a bug here, it's probably with Chromedriver, but Capybara should be able to provide insight into that specific call.

@marcoadkins
Copy link
Author

@titusfortner Good eye. Well regardless I got things working by removing the w3c: false setting so not sure what exactly that says but maybe capybara will have more insight.

@titusfortner
Copy link
Member

Ah, yes.

Chrome is the only driver that has a JSON Wire Protocol mode still (w3c: false).

Your code sends to Selenium Server and says use JWP, but JWP classes aren't wired up to use the newest endpoints and methods, so Server doesn't understand what Ruby wants it to do...

Capybara is assuming that you either won't be in JWP mode, or won't be going through the Server.

@titusfortner
Copy link
Member

I'm opening this back up because I think bindings should prevent setting w3c to false in Selenium 4 since we no longer support OSS endpoints.

@titusfortner titusfortner reopened this Mar 16, 2022
@titusfortner titusfortner changed the title [🐛 Bug]: Selenium::WebDriver::Error::ScriptTimeoutError: Unable to execute request for an existing session: [🐛 Bug]: Setting chrome to w3c: false in Selenium 4 causes errors Mar 16, 2022
@diemol
Copy link
Member

diemol commented Apr 12, 2022

But that would mean that Selenium code needs to analyze the Chrome options, and ideally the JSON Wire Protocol in ChromeDriver will go away at some point soon.

@diemol
Copy link
Member

diemol commented Jun 8, 2022

In a previous TLC meeting it was decided that the bindings won't allow this to be set. So I am adding labels for each language so we can work on this.

@diemol
Copy link
Member

diemol commented Jun 8, 2022

Given that w3c: false does not work in all bindings except Java, we should throw an error when the user tries to set this. In Java we are in the process of removing JWP support, so we will throw a warning, and when the code supporting JWP is gone, we will throw an error.

@diemol diemol added this to the 4.3 milestone Jun 8, 2022
@diemol
Copy link
Member

diemol commented Jun 13, 2022

Implemented, warnings for Java. I won't remove the java label since those warnings need to be converted to an error for 4.4

diemol added a commit that referenced this issue Jun 13, 2022
@diemol diemol modified the milestones: 4.3, 4.4 Jun 24, 2022
elgatov pushed a commit to elgatov/selenium that referenced this issue Jun 27, 2022
elgatov pushed a commit to elgatov/selenium that referenced this issue Jun 27, 2022
@titusfortner titusfortner added the help wanted Issues looking for contributions label Jul 20, 2022
@github-actions
Copy link

This issue is looking for contributors.

Please comment below or reach out to us through our IRC/Slack/Matrix channels if you are interested.

@titusfortner
Copy link
Member

I'm not sure what to do with the Java piece. I'm updating the warning being logged to reference "false" instead of "true," and I'm not sure we should throw the errors until we stop supporting the Java handshake. I'm removing the 4.4 label because I think this is good enough. We can close this or add it to another list for when removing handshake.

@diemol diemol removed the C-java label Aug 8, 2022
@diemol
Copy link
Member

diemol commented Aug 8, 2022

Closing since Java will throw when a user sets the w3c to false.

This is not the same as supporting the handshake JWP/W3C because a user could send W3C caps in the session request, and still send the w3c: false. Which looks like a W3C session, but then ChromeDriver would act differently. This is more like a special case.

@diemol diemol closed this as completed Aug 8, 2022
@github-actions
Copy link

github-actions bot commented Sep 8, 2022

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked and limited conversation to collaborators Sep 8, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
help wanted Issues looking for contributions I-defect
Projects
None yet
Development

No branches or pull requests

3 participants