SeleniumHQ
[🐛 Bug]: JdkWebSocket initial request execution error - Selenium Grid Dynamic Node
Description
Error
I want to receive the Browser Logs using Bidi from a dynamic grid.
When i configure the grid with a standard chrome node instance I am able to receive all Logs from the browser.
When i configure the grid with a dynamic node (using the same chrome node in the toml file) I am getting the below mentioned Error message:
Caused by: jdk.internal.net.http.websocket.CheckFailedException: Unexpected HTTP response status code 400
Reproduction
I have created a test project (gradle) to reproduce the error at:
https://github.com/andy-schulz/collections/tree/main/selenium/bidi_browser_logs
The folder scripts contains:
- docker-compose.yml
- dynamic_config.toml
The compose file contains two configurations:
- docker-node: which causes the error when the test runs
- chrome: which produces the correct result, the logs are received.
The following Tests are created in TestBrowserLogsFromGrid.java
- workingLogTest: receiving the Logs the conventional way working on both node configs
- bidiLogTest: only works on the chrome node but not on the docker-node
StackTrace
org.openqa.selenium.remote.http.ConnectionFailedException: JdkWebSocket initial request execution error
Build info: version: '4.35.0', revision: '1c58e5028b'
System info: os.name: 'Windows 11', os.arch: 'amd64', os.version: '10.0', java.version: '17.0.14'
Driver info: driver.version: unknown
at org.openqa.selenium.remote.http.jdk.JdkHttpClient.openSocket(JdkHttpClient.java:253)
at org.openqa.selenium.bidi.Connection.
Reproducible Code
https://github.com/andy-schulz/collections/tree/main/selenium/bidi_browser_logs
@andy-schulz, thank you for creating this issue. We will troubleshoot it as soon as we can.
Selenium Triage Team: remember to follow the Triage Guide
@andy-schulz, for Node Docker, it has a little bit different, environment variable SE_NODE_GRID_URL pass through node docker to browser node run inside, which cause incorrect se:forwardCdp
In Node Docker TOML config, set grid-url there for node-docker only - https://github.com/andy-schulz/collections/pull/1
I will recheck in Docker Selenium Grid to see how to make this work resilient without extra config later.
@VietND96 thanks a lot, I did try your configuration in our internal network and it works great as long as the docker-node runs on the same server as the selenium hub.
When i start a second node on an additional server with the following configuration it is still having an issue.
internal access: https://selenium.myCompany.io Hub running on: 172.16.10.2 Node running on: 172.16.10.3
Maybe you have already an obvious suggestion I am missing on how to configure this situation.
configs i tried:
compose file for node on 172.16.10.3
node-docker:
image: selenium/node-docker:4.35.0
volumes:
- /home/selenium/assets:/opt/selenium/assets
- ./config.toml:/opt/selenium/docker.toml
- /var/run/docker.sock:/var/run/docker.sock
- ./downloads:/home/seluser/Downloads
environment:
- SE_EVENT_BUS_HOST=172.16.10.2
- SE_EVENT_BUS_PUBLISH_PORT=4442
- SE_EVENT_BUS_SUBSCRIBE_PORT=4443
- SE_ENABLE_TRACING=false
- SE_OPTS=--enable-managed-downloads true --host 172.16.10.3 --log-level FINE
- SE_NODE_CONNECTION_LIMIT_PER_SESSION=100
ports:
- "5555:5555"
toml file
[node]
max-sessions = 16
grid-url = "https://selenium.myCompany.io"
# grid-url = "http://172.16.10.2:4444"
[docker]
configs = [
"selenium/standalone-chrome:136.0", '{"browserName": "chrome"}'
]
url = "http://127.0.0.1:2375"
Started Node Session:
06:21:24.017 INFO [LocalNode.newSession] - Session created by the Node. Id: fcc2594a88f2d8e5e6ef2bff5c7bfe3d,
Caps: Capabilities {
acceptInsecureCerts: false,
browserName: chrome,
browserVersion: 136.0.7103.113,
chrome: {
chromedriverVersion: 136.0.7103.113 (76fa3c17824...,
userDataDir: /tmp/.org.chromium.Chromium...},
fedcm:accounts: true,
goog:chromeOptions: {debuggerAddress: localhost:32937},
networkConnectionEnabled: false,
pageLoadStrategy: normal,
platformName: linux,
proxy: Proxy(),
se:cdp: wss://selenium.myCompany.io...,
se:cdpVersion: 136.0.7103.113,
se:containerName: cc98a7290bda,
se:downloadsEnabled: true,
se:forwardCdp: ws://172.18.0.4:4444/sessio...,
se:gridWebSocketUrl: ws://172.16.10.3:4444/sessi...,
se:noVncPort: 7900,
se:recordVideo: true,
se:vnc: wss://selenium.myCompany.io...,
se:vncEnabled: true,
se:vncLocalAddress: ws://172.18.0.4:7900,
setWindowRect: true,
strictFileInteractability: false,
timeouts: {implicit: 0, pageLoad: 300000, script: 30000},
unhandledPromptBehavior: dismiss and notify,
webSocketUrl: wss://selenium.myCompany.io...,
webauthn:extension:credBlob: true,
webauthn:extension:largeBlob: true,
webauthn:extension:minPinLength: true,
webauthn:extension:prf: true,
webauthn:virtualAuthenticators: true
}
Stacktrace:
06:21:25.106 INFO [ProxyNodeWebsockets.createWsEndPoint] - Establishing connection to ws://172.16.10.3:4444/session/fcc2594a88f2d8e5e6ef2bff5c7bfe3d/se/bidi
06:21:25.111 WARN [ProxyNodeWebsockets.createWsEndPoint] - Connecting to upstream websocket failed
org.openqa.selenium.remote.http.ConnectionFailedException: JdkWebSocket initial request execution error
Build info: version: '4.35.0', revision: '1c58e5028b'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '6.8.0-71-generic', java.version: '21.0.8'
Driver info: driver.version: unknown
at org.openqa.selenium.remote.http.jdk.JdkHttpClient.openSocket(JdkHttpClient.java:253)
at org.openqa.selenium.remote.tracing.TracedHttpClient.openSocket(TracedHttpClient.java:45)
at org.openqa.selenium.grid.node.ProxyNodeWebsockets.createWsEndPoint(ProxyNodeWebsockets.java:238)
at org.openqa.selenium.grid.node.ProxyNodeWebsockets.lambda$findBiDiEndpoint$3(ProxyNodeWebsockets.java:183)
at java.base/java.util.Optional.map(Optional.java:260)
at org.openqa.selenium.grid.node.ProxyNodeWebsockets.findBiDiEndpoint(ProxyNodeWebsockets.java:183)
at org.openqa.selenium.grid.node.ProxyNodeWebsockets.apply(ProxyNodeWebsockets.java:112)
at org.openqa.selenium.grid.node.ProxyNodeWebsockets.apply(ProxyNodeWebsockets.java:48)
at org.openqa.selenium.netty.server.WebSocketUpgradeHandler.handleHttpRequest(WebSocketUpgradeHandler.java:137)
at org.openqa.selenium.netty.server.WebSocketUpgradeHandler.channelRead(WebSocketUpgradeHandler.java:100)
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.onHttpRequestChannelRead(WebSocketServerExtensionHandler.java:158)
at io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.channelRead(WebSocketServerExtensionHandler.java:82)
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:1357)
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:868)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:796)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:732)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:658)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998)
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:1583)
Caused by: java.net.ConnectException
at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1065)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:227)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:280)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$2(PlainHttpConnection.java:238)
at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
... 1 more
Caused by: java.nio.channels.ClosedChannelException
at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:202)
at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:786)
at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:874)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:210)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:571)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:212)
... 9 more
Hi @andy-schulz, in compose file for node on 172.16.10.3, can you try to remove --host in this env var
- SE_OPTS=--enable-managed-downloads true --log-level FINE
@VietND96 Without the --host flagi am not able to register the node.
The node is trying to register itself with the docker IP.
node-docker-1 | 09:05:33.876 INFO [NodeServer$2.start] - Starting registration process for Node http://172.18.0.2:5555
node-docker-1 | 09:05:33.877 INFO [NodeServer.execute] - Started Selenium node 4.35.0 (revision 1c58e5028b): http://172.18.0.2:5555
node-docker-1 | 09:05:33.918 INFO [NodeServer$2.lambda$start$2] - Sending registration event...
node-docker-1 | 09:05:43.937 INFO [NodeServer$2.lambda$start$2] - Sending registration event...
On the hub i am getting then the following exception. I thought thats was the --host flag for.
07:06:14.385 DEBUG [LocalNodeRegistry.add] - Exception while adding Node http://172.18.0.2:5555
selenium-hub | java.io.UncheckedIOException: java.net.ConnectException
selenium-hub | at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:500)
selenium-hub | at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
selenium-hub | at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)
selenium-hub | at org.openqa.selenium.remote.http.jdk.JdkHttpClient.lambda$executeAsync$2(JdkHttpClient.java:387)
selenium-hub | at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
selenium-hub | at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
selenium-hub | at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
selenium-hub | at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
selenium-hub | at java.base/java.lang.Thread.run(Thread.java:1583)
selenium-hub | Caused by: java.net.ConnectException
selenium-hub | at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:955)
selenium-hub | at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:133)
selenium-hub | at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:459)
selenium-hub | ... 8 more
selenium-hub | Caused by: java.net.ConnectException
selenium-hub | at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1065)
selenium-hub | at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:227)
selenium-hub | at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:280)
selenium-hub | at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$2(PlainHttpConnection.java:238)
selenium-hub | at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
selenium-hub | at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
selenium-hub | at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
selenium-hub | at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)
selenium-hub | ... 3 more
selenium-hub | Caused by: java.nio.channels.ClosedChannelException
selenium-hub | at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:202)
selenium-hub | at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:786)
selenium-hub | at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:874)
selenium-hub | at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:210)
selenium-hub | at java.base/java.security.AccessController.doPrivileged(AccessController.java:571)
selenium-hub | at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:212)
selenium-hub | ... 9 more
selenium-hub | 07:06:17.151 DEBUG [LoggingHandler.channelRead] - [id: 0x075cfdd3, L:/[0:0:0:0:0:0:0:0]:4444] READ: [id: 0x7136db03, L:/172.18.0.2:4444 - R:/172.18.0.1:41636]
selenium-hub | 07:06:17.151 DEBUG [LoggingHandler.channelRead] - [id: 0x075cfdd3, L:/[0:0:0:0:0:0:0:0]:4444] READ: [id: 0x0db4244a, L:/172.18.0.2:4444 - R:/172.18.0.1:41638]
selenium-hub | 07:06:17.152 DEBUG [LoggingHandler.channelReadComplete] - [id: 0x075cfdd3, L:/[0:0:0:0:0:0:0:0]:4444] READ COMPLETE
selenium-hub | 07:06:17.153 DEBUG [RequestConverter.channelRead0] - Incoming message: DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)