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]: OpenQA.Selenium.WebDriverException : Unexpected error creating WebSocket DevTools session. #14714

Open
MJB222398 opened this issue Nov 5, 2024 · 9 comments

Comments

@MJB222398
Copy link

MJB222398 commented Nov 5, 2024

What happened?

Jenkins running a 35 minutes worth of tests on Chrome, Edge, and Firefox in parallel using Docker selenium grid. Chrome and Edge tests all passed but 6/7 minutes in I had a Firefox one fail with the below exception. After this one failed test subsequent tests on Firefox were all fine. Tests runs following this were all fine and no code or environmental changes were made before or after this failure so the issue is intermittent.

OpenQA.Selenium.WebDriverException : Unexpected error creating WebSocket DevTools session.
----> System.TimeoutException : Could not connect to browser within 30 seconds
at OpenQA.Selenium.Remote.RemoteWebDriver.GetDevToolsSession(DevToolsOptions options)
at OpenQA.Selenium.Remote.RemoteWebDriver.GetDevToolsSession()
at OpenQA.Selenium.JavaScriptEngine.<>c__DisplayClass8_0.<.ctor>b__0()
at System.Lazy1.ViaFactory(LazyThreadSafetyMode mode) at System.Lazy1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
at System.Lazy`1.CreateValue()
at OpenQA.Selenium.JavaScriptEngine.StartEventMonitoring()
--TimeoutException
at OpenQA.Selenium.DevTools.WebSocketConnection.Start(String url)
at OpenQA.Selenium.DevTools.DevToolsSession.InitializeSocketConnection()
at OpenQA.Selenium.DevTools.DevToolsSession.StartSession()
at OpenQA.Selenium.Remote.RemoteWebDriver.<>c__DisplayClass29_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at OpenQA.Selenium.Remote.RemoteWebDriver.GetDevToolsSession(DevToolsOptions options)

How can we reproduce the issue?

var driverOptions = new FirefoxOptions() { EnableDevToolsProtocol = true };
driverOptions.AddArguments("-profile", "home/seluser/.mozilla/firefox/seluser_profile");

var seleniumRemoteWebDriver = new RemoteWebDriver(
        remoteAddress: new Uri(_driverConfiguration.Url),
        capabilities: driverOptions.ToCapabilities(),
        commandTimeout: TimeSpan.FromSeconds(_driverConfiguration.CommandTimeout));
seleniumRemoteWebDriver.Manage().Window.Maximize();

var jsEngine = new JavaScriptEngine(seleniumRemoteWebDriver)

jsEngine.JavaScriptConsoleApiCalled += (_, e) => { lock (_consoleLogsLock) { _consoleLogs.Add(e); } };
await jsEngine.StartEventMonitoring();

Relevant log output

16:49:09.528 INFO [LocalNode.newSession] - Session created by the Node. Id: 2b75b239-f11e-402a-b8a4-1f80fa901383, Caps: Capabilities {acceptInsecureCerts: false, browserName: firefox, browserVersion: 128.0.3, moz:accessibilityChecks: false, moz:buildID: 20240725162350, moz:debuggerAddress: 127.0.0.1:15564, moz:firefoxOptions: {args: [-profile, home/seluser/.mozilla/firef...], prefs: {remote.active-protocols: 3}}, moz:geckodriverVersion: 0.34.0, moz:headless: false, moz:platformVersion: 5.4.0-189-generic, moz:processID: 8045, moz:profile: /home/seluser/.mozilla/fire..., moz:shutdownTimeout: 60000, moz:webdriverClick: true, moz:windowless: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://localhost:4444/session..., se:cdpVersion: 85.0, se:containerName: , se:noVncPort: 7900, se:vnc: ws://localhost:4444/session..., se:vncEnabled: true, se:vncLocalAddress: ws://192.168.32.7:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, userAgent: Mozilla/5.0 (X11; Linux x86...}
16:49:09.549 INFO [ProxyNodeWebsockets.createWsEndPoint] - Establishing connection to ws://127.0.0.1:15564/devtools/browser/fbcc0353-f46e-4150-a50f-0ea5bd924b23
16:49:15.601 INFO [SessionSlot.stop] - Stopping session 2b75b239-f11e-402a-b8a4-1f80fa901383
16:49:17.232 INFO [LocalNode.newSession] - Session created by the Node. Id: 62a74535-935b-4865-9940-1a4c1f79bce5, Caps: Capabilities {acceptInsecureCerts: false, browserName: firefox, browserVersion: 128.0.3, moz:accessibilityChecks: false, moz:buildID: 20240725162350, moz:debuggerAddress: 127.0.0.1:28252, moz:firefoxOptions: {args: [-profile, home/seluser/.mozilla/firef...], prefs: {remote.active-protocols: 3}}, moz:geckodriverVersion: 0.34.0, moz:headless: false, moz:platformVersion: 5.4.0-189-generic, moz:processID: 8435, moz:profile: /home/seluser/.mozilla/fire..., moz:shutdownTimeout: 60000, moz:webdriverClick: true, moz:windowless: false, pageLoadStrategy: normal, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://localhost:4444/session..., se:cdpVersion: 85.0, se:containerName: , se:noVncPort: 7900, se:vnc: ws://localhost:4444/session..., se:vncEnabled: true, se:vncLocalAddress: ws://192.168.32.7:7900, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, userAgent: Mozilla/5.0 (X11; Linux x86...}
16:49:17.249 WARN [DefaultChannelPipeline.onUnhandledInboundException] - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.lang.NullPointerException: Cannot invoke "org.openqa.selenium.remote.http.HttpRequest.setContent(org.openqa.selenium.remote.http.Contents$Supplier)" because "this.request" is null
	at org.openqa.selenium.netty.server.RequestConverter.channelRead0(RequestConverter.java:146)
	at org.openqa.selenium.netty.server.RequestConverter.channelRead0(RequestConverter.java:53)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:102)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:102)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
	at org.openqa.selenium.netty.server.WebSocketUpgradeHandler.channelRead(WebSocketUpgradeHandler.java:98)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
	at io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.channelRead(WebSocketServerExtensionHandler.java:90)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
	at io.netty.handler.codec.http.HttpServerKeepAliveHandler.channelRead(HttpServerKeepAliveHandler.java:64)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)

The above repeated many times, and then the below repeated many times

16:49:31.011 WARN [DefaultChannelPipeline.onUnhandledInboundException] - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.lang.NullPointerException

The driver logs didn't contain anything about this:

2024-11-04 16:49:16.297 DEBUG HttpCommandExecutor: Executing command: []: newSession {"capabilities":{"firstMatch":[{"browserName":"firefox","moz:firefoxOptions":{"args":["-profile","home/seluser/.mozilla/firefox/seluser_profile"],"prefs":{"remote.active-protocols":3}},"moz:debuggerAddress":true}]}}
2024-11-04 16:49:16.297 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:4444/wd/hub/session', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.23.0
  User-Agent: (.net linux)
  Content-Type: application/json; charset=utf-8
  Content-Length: 215
}
{"capabilities":{"firstMatch":[{"browserName":"firefox","moz:firefoxOptions":{"args":["-profile","home/seluser/.mozilla/firefox/seluser_profile"],"prefs":{"remote.active-protocols":3}},"moz:debuggerAddress":true}]}}
2024-11-04 16:49:17.238 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 1803
  Content-Type: application/json; charset=utf-8
}
2024-11-04 16:49:17.238 DEBUG HttpCommandExecutor: Response: (62a74535-935b-4865-9940-1a4c1f79bce5 Success: System.Collections.Generic.Dictionary`2[System.String,System.Object])
2024-11-04 16:49:17.238 DEBUG HttpCommandExecutor: Executing command: [62a74535-935b-4865-9940-1a4c1f79bce5]: maximizeWindow {}
2024-11-04 16:49:17.238 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:4444/wd/hub/session/62a74535-935b-4865-9940-1a4c1f79bce5/window/maximize', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.23.0
  User-Agent: (.net linux)
  Content-Type: application/json; charset=utf-8
  Content-Length: 2
}
{}
2024-11-04 16:49:17.241 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 50
  Content-Type: application/json; charset=utf-8
}
2024-11-04 16:49:17.241 DEBUG HttpCommandExecutor: Response: ( Success: System.Collections.Generic.Dictionary`2[System.String,System.Object])

Operating System

Ubuntu

Selenium version

4.23.0

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

Firefox 128.0

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

moz:geckodriverVersion: 0.34.0

Are you using Selenium Grid?

4.23.0-20240727

Copy link

github-actions bot commented Nov 5, 2024

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

@diemol
Copy link
Member

diemol commented Nov 5, 2024

This seems related to Firefox. I don't know how we can help with just a stack trace.

@MJB222398
Copy link
Author

@diemol There are logs from the selenium grid and driver too

@diemol
Copy link
Member

diemol commented Nov 5, 2024

I know, but we have no context at all. I can only see the exception after interacting with Firefox.

@MJB222398
Copy link
Author

Have added simplified code to show what it was doing. Its throwing on the jsEngine.StartEventMonitoring() line

@nvborisenko
Copy link
Member

nvborisenko commented Nov 9, 2024

I have tried the following:

using OpenQA.Selenium;
using OpenQA.Selenium.Firefox;

using var driver = new FirefoxDriver(new FirefoxOptions{ BrowserVersion = "128", EnableDevToolsProtocol = true });

var jsEngine = new JavaScriptEngine(driver);

await jsEngine.StartEventMonitoring();

It fails, and in webdriver output I see:

1731190028175   geckodriver     INFO    Listening on 127.0.0.1:51613
1731190028231   mozrunner::runner       INFO    Running command: MOZ_CRASHREPORTER="1" MOZ_CRASHREPORTER_NO_REPORT="1" MOZ_CRASHREPORTER_SHUTDOWN="1" MOZ_NO_REMOTE="1" "/Use ... s" "localhost" "-foreground" "-no-remote" "-profile" "/var/folders/jn/3vpm436n7s95bq9bm5sd6cfh0000gn/T/rust_mozprofileJHdSD7"
console.warn: services.settings: Ignoring preference override of remote settings server
console.warn: services.settings: Allow by setting MOZ_REMOTE_SETTINGS_DEVTOOLS=1 in the environment
1731190028606   Marionette      INFO    Marionette enabled
console.error: "Warning: unrecognized command line flag" "-remote-allow-hosts"
1731190029041   Marionette      INFO    Listening on port 51620
console.error: Policies: 
  Download failed - ERROR_NETWORK_FAILURE - file:///opt/PrinterInstallerClient/PrinterLogic.xpi
Read port: 51620
WebDriver BiDi listening on ws://127.0.0.1:51615
console.error: Policies: 
  Download failed - ERROR_NETWORK_FAILURE - https://addons.mozilla.org/firefox/downloads/file/4332526/phish_jail_ff-1.0.0.xpi
2024-11-10 01:07:09.632 firefox[11945:128675] +[IMKClient subclass]: chose IMKClient_Legacy
2024-11-10 01:07:09.633 firefox[11945:128675] +[IMKInputSession subclass]: chose IMKInputSession_Legacy
DevTools listening on ws://127.0.0.1:51615/devtools/browser/79c5778d-d7d5-4365-a83c-fd0fc65777e6
1731190030623   RemoteAgent     INFO    Perform WebSocket upgrade for incoming connection from 127.0.0.1:51633
1731190030625   CDP     WARN    Support for the Chrome DevTools Protocol (CDP) in Firefox will be deprecated after Firefox 128 (ESR) and will be removed in a later release. CDP users should consider migrating to WebDriver BiDi. See https://bugzilla.mozilla.org/show_bug.cgi?id=1872254
1731190030625   CDP     WARN    Invalid browser preferences for CDP. Set "fission.webContentIsolationStrategy"to 0 and "fission.bfcacheInParent" to false before Firefox starts.
1731190030661   CDP     WARN    Support for the Chrome DevTools Protocol (CDP) in Firefox will be deprecated after Firefox 128 (ESR) and will be removed in a later release. CDP users should consider migrating to WebDriver BiDi. See https://bugzilla.mozilla.org/show_bug.cgi?id=1872254
1731190030661   CDP     WARN    Invalid browser preferences for CDP. Set "fission.webContentIsolationStrategy"to 0 and "fission.bfcacheInParent" to false before Firefox starts.
console.error: (new UnknownMethodError("Log.clear", "chrome://remote/content/cdp/Error.sys.mjs", 18))
1731190030671   CDP     ERROR   UnknownMethodError: Log.clear:
        RemoteAgentError@chrome://remote/content/cdp/Error.sys.mjs:18:5
        UnknownMethodError@chrome://remote/content/cdp/Error.sys.mjs:101:7
        execute@chrome://remote/content/cdp/domains/DomainCache.sys.mjs:92:13
        receiveMessage@chrome://remote/content/cdp/sessions/ContentProcessSession.sys.mjs:79:45
caused by: 
1731190030710   Marionette      INFO    Stopped listening on port 51620

And in internal selenium dotnet logs I see:

01:18:02.414 TRACE DevToolsSession: CDP SND >> 4 Log.clear: {}
01:18:02.418 TRACE DevToolsSession: CDP RCV << {"id":4,"error":{"message":"Log.clear","data":"RemoteAgentError@chrome://remote/content/cdp/Error.sys.mjs:18:5\nUnknownMethodError@chrome://remote/content/cdp/Error.sys.mjs:101:7\nexecute@chrome://remote/content/cdp/domains/DomainCache.sys.mjs:92:13\nreceiveMessage@chrome://remote/content/cdp/sessions/ContentProcessSession.sys.mjs:79:45\n"},"sessionId":"c2fd05f1-b463-4f3a-b349-135c2a8add0b"}

Seems the issue should be addressed to Firefox.

@nvborisenko
Copy link
Member

@MJB222398 given that you know how selenium library works internally, do you think this issue of library itself? Or it is more related to remote end?

@MJB222398
Copy link
Author

I'll pick this back up in a couple of days if thats OK. Lots of work at the moment that I need to prioritise. Hope thats OK

@MJB222398
Copy link
Author

@nvborisenko Do you mean you get that error every time with your code? Mine I see an error incredibly rarely. I'm not seeing the connection between your error and mine? I'm afraid I am not familiar enough with internal implementation for Selenium so cannot comment on where the root cause likely lies.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants