[🐛 Bug]: Dynamic Grid setup fails when the docker images are missing locally

[krmahadevan]

What happened?

When we attempt at following the documentation of Dynamic Grid the docker node does not come up and crashes.

How can we reproduce the issue?

Ensure that you dont have any of the selenium related docker container images in your machine by running

1. docker container prune to prune the images being used by stopped containers
2. docker rmi $(docker images | grep selenium | awk '{print $3}') clean up all selenium images

Create a docker-compose file named docker-compose-v3-dynamic-grid.yml that looks like below:

# To execute this docker-compose yml file use `docker-compose -f docker-compose-v3-dynamic-grid.yml up`
# Add the `-d` flag at the end for detached execution
# To stop the execution, hit Ctrl+C, and then `docker-compose -f docker-compose-v3-dynamic-grid.yml down`
version: "3"
services:
  node-docker:
    image: selenium/node-docker:4.6.0-20221104
    volumes:
      - ./config.toml:/opt/bin/config.toml
    depends_on:
      - selenium-hub-dynamic
    environment:
      - SE_EVENT_BUS_HOST=selenium-hub-dynamic
      - SE_EVENT_BUS_PUBLISH_PORT=4442
      - SE_EVENT_BUS_SUBSCRIBE_PORT=4443
    ports:
      - "5005:5005"
     
  selenium-hub-dynamic:
    image: selenium/hub:4.6.0-20221104
    container_name: selenium-hub-dynamic
    ports:
      - "4442:4442"
      - "4443:4443"
      - "4455:4444"

In the same directory create a toml configuration file named config.toml with its contents as below:

[docker]
# Configs have a mapping between the Docker image to use and the capabilities that need to be matched to
# start a container with the given image.
configs = [
    "selenium/standalone-firefox:4.6.0-20221104", "{\"browserName\": \"firefox\"}",
    "selenium/standalone-chrome:4.6.0-20221104", "{\"browserName\": \"chrome\"}",
    "selenium/standalone-edge:4.6.0-20221104", "{\"browserName\": \"MicrosoftEdge\"}"
    ]
    
# URL for connecting to the docker daemon
# Most simple approach, leave it as http://127.0.0.1:2375, and mount /var/run/docker.sock.
# 127.0.0.1 is used because interally the container uses socat when /var/run/docker.sock is mounted 
# If var/run/docker.sock is not mounted: 
# Windows: make sure Docker Desktop exposes the daemon via tcp, and use http://host.docker.internal:2375.
# macOS: install socat and run the following command, socat -4 TCP-LISTEN:2375,fork UNIX-CONNECT:/var/run/docker.sock,
# then use http://host.docker.internal:2375.
# Linux: varies from machine to machine, please mount /var/run/docker.sock. If this does not work, please create an issue.
# I am on mac
url =  "http://host.docker.internal:2375"

# Docker image used for video recording
#video-image = "selenium/video:ffmpeg-4.3.1-20220531"

# Uncomment the following section if you are running the node on a separate VM
# Fill out the placeholders with appropriate values
#[server]
#host = "10.136.130.15"#<ip-from-node-machine>
#port = "5555"#<port-from-node-machine>

Setup socat forwarding (I am on Mac and so I installed socat and run the following command, socat -4 TCP-LISTEN:2375,fork UNIX-CONNECT:/var/run/docker.sock

Now bring up the nodes by running docker-compose -f docker-compose-v3-dynamic-grid.yml up

### Relevant log output

```shell
sunny-node-docker-1   | 10:31:07.650 INFO [PullImage.apply] - Pulling Reference{domain='docker.io', name='selenium/standalone-firefox', tag='4.6.0-20221104', digest='null'}
sunny-node-docker-1   | java.lang.reflect.InvocationTargetException
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
sunny-node-docker-1   |         at java.base/java.lang.reflect.Method.invoke(Method.java:566)
sunny-node-docker-1   |         at org.openqa.selenium.grid.Bootstrap.runMain(Bootstrap.java:77)
sunny-node-docker-1   |         at org.openqa.selenium.grid.Bootstrap.main(Bootstrap.java:70)
sunny-node-docker-1   | Caused by: org.openqa.selenium.grid.config.ConfigException: java.lang.reflect.InvocationTargetException
sunny-node-docker-1   |         at org.openqa.selenium.grid.config.MemoizedConfig.getClass(MemoizedConfig.java:115)
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.config.NodeOptions.getNode(NodeOptions.java:152)
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.httpd.NodeServer.createHandlers(NodeServer.java:128)
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.httpd.NodeServer.asServer(NodeServer.java:184)
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.httpd.NodeServer.execute(NodeServer.java:239)
sunny-node-docker-1   |         at org.openqa.selenium.grid.TemplateGridCommand.lambda$configure$4(TemplateGridCommand.java:129)
sunny-node-docker-1   |         at org.openqa.selenium.grid.Main.launch(Main.java:83)
sunny-node-docker-1   |         at org.openqa.selenium.grid.Main.go(Main.java:57)
sunny-node-docker-1   |         at org.openqa.selenium.grid.Main.main(Main.java:42)
sunny-node-docker-1   |         ... 6 more
sunny-node-docker-1   | Caused by: java.lang.reflect.InvocationTargetException
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
sunny-node-docker-1   |         at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
sunny-node-docker-1   |         at java.base/java.lang.reflect.Method.invoke(Method.java:566)
sunny-node-docker-1   |         at org.openqa.selenium.grid.config.ClassCreation.callCreateMethod(ClassCreation.java:50)
sunny-node-docker-1   |         at org.openqa.selenium.grid.config.MemoizedConfig.lambda$getClass$4(MemoizedConfig.java:100)
sunny-node-docker-1   |         at java.base/java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1737)
sunny-node-docker-1   |         at org.openqa.selenium.grid.config.MemoizedConfig.getClass(MemoizedConfig.java:95)
sunny-node-docker-1   |         ... 14 more
sunny-node-docker-1   | Caused by: java.lang.IllegalArgumentException: non-positive contentLength: 0
sunny-node-docker-1   |         at java.net.http/java.net.http.HttpRequest$BodyPublishers.fromPublisher(HttpRequest.java:539)
sunny-node-docker-1   |         at org.openqa.selenium.remote.http.jdk.JdkHttpMessages.notChunkingBodyPublisher(JdkHttpMessages.java:124)
sunny-node-docker-1   |         at org.openqa.selenium.remote.http.jdk.JdkHttpMessages.createRequest(JdkHttpMessages.java:76)
sunny-node-docker-1   |         at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:280)
sunny-node-docker-1   |         at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:55)
sunny-node-docker-1   |         at org.openqa.selenium.docker.v1_41.PullImage.apply(PullImage.java:63)
sunny-node-docker-1   |         at org.openqa.selenium.docker.v1_41.V141Docker.getImage(V141Docker.java:80)
sunny-node-docker-1   |         at org.openqa.selenium.docker.Docker.lambda$getImage$0(Docker.java:51)
sunny-node-docker-1   |         at java.base/java.util.Optional.map(Optional.java:265)
sunny-node-docker-1   |         at org.openqa.selenium.docker.Docker.getImage(Docker.java:51)
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.docker.DockerOptions.lambda$loadImages$4(DockerOptions.java:260)
sunny-node-docker-1   |         at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
sunny-node-docker-1   |         at java.base/java.lang.Thread.run(Thread.java:829)
sunny-node-docker-1   | Exception in thread "Thread-0" java.lang.NullPointerException
sunny-node-docker-1   |         at org.openqa.selenium.grid.node.httpd.NodeServer.lambda$new$0(NodeServer.java:80)
sunny-node-docker-1   |         at java.base/java.lang.Thread.run(Thread.java:829)
sunny-node-docker-1   | 2022-12-01 10:31:08,079 INFO exited: selenium-grid-docker (exit status 1; not expected)

Operating System

macOS

Selenium version

Java 4.6.0

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

Not relevant

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

Not relevant

Are you using Selenium Grid?

4.6.0

[github-actions]

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

[victortanase]

After pulling the images manually I still cannot get any seession(as described in SeleniumHQ/docker-selenium#1719):

selenium-node-docker-1 | 09:18:15.188 INFO [Docker.getImage] - Obtaining image: selenium/standalone-chrome:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.190 INFO [Docker.getImage] - Obtaining image: selenium/standalone-firefox:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.190 INFO [Docker.getImage] - Obtaining image: selenium/standalone-edge:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.193 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-chrome', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.193 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-edge', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.193 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-firefox', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.259 INFO [Docker.getImage] - Obtaining image: selenium/video:ffmpeg-4.3.1-20221202
selenium-node-docker-1 | 09:18:15.259 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/video', tag='ffmpeg-4.3.1-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.290 INFO [Docker.getImage] - Obtaining image: selenium/video:ffmpeg-4.3.1-20221202
selenium-node-docker-1 | 09:18:15.290 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/video', tag='ffmpeg-4.3.1-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.321 INFO [Docker.getImage] - Obtaining image: selenium/standalone-chrome:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.322 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-chrome', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.368 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: chrome} to docker image selenium/standalone-chrome:4.7.0-20221202 8 times
selenium-node-docker-1 | 09:18:15.368 INFO [Docker.getImage] - Obtaining image: selenium/standalone-firefox:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.368 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-firefox', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.392 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: firefox} to docker image selenium/standalone-firefox:4.7.0-20221202 8 times
selenium-node-docker-1 | 09:18:15.393 INFO [Docker.getImage] - Obtaining image: selenium/standalone-edge:4.7.0-20221202
selenium-node-docker-1 | 09:18:15.393 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-edge', tag='4.7.0-20221202', digest='null'}
selenium-node-docker-1 | 09:18:15.415 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: MicrosoftEdge} to docker image selenium/standalone-edge:4.7.0-20221202 8 times
selenium-node-docker-1 | 09:18:15.472 INFO [Node.] - Binding additional locator mechanisms: name, id, relative
selenium-node-docker-1 | 09:18:15.745 INFO [NodeServer$1.start] - Starting registration process for Node http://172.19.0.3:5555
selenium-node-docker-1 | 09:18:15.746 INFO [NodeServer.execute] - Started Selenium node 4.7.0 (revision 52e3a49ea2): http://172.19.0.3:5555
selenium-node-docker-1 | 09:18:15.790 INFO [NodeServer$1.lambda$start$1] - Sending registration event...
selenium-hub | 09:18:15.907 INFO [Node.] - Binding additional locator mechanisms: name, relative, id
selenium-hub | 09:18:16.493 INFO [GridModel.setAvailability] - Switching Node db79fa29-b5e8-4efa-8f2b-70c50c4939f3 (uri: http://172.19.0.3:5555) from DOWN to UP
selenium-hub | 09:18:16.497 INFO [LocalDistributor.add] - Added node db79fa29-b5e8-4efa-8f2b-70c50c4939f3 at http://172.19.0.3:5555. Health check every 120s
selenium-node-docker-1 | 09:18:16.505 INFO [NodeServer.lambda$createHandlers$2] - Node has been added
selenium-hub | 09:18:38.537 INFO [LocalDistributor.newSession] - Session request received by the Distributor:
selenium-hub | [Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}, se:name: My simple test}]
selenium-node-docker-1 | 09:18:38.577 INFO [DockerSessionFactory.apply] - Starting session for Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}, se:name: My simple test}
selenium-node-docker-1 | 09:18:38.578 INFO [DockerSessionFactory.apply] - Creating container...
selenium-node-docker-1 | 09:18:38.653 INFO [Container.] - Created container b576f445515fa9801980310a176124c9158eb619a0472f237945526db1420e8b
selenium-node-docker-1 | 09:18:38.653 INFO [Container.start] - Starting container b576f445515fa9801980310a176124c9158eb619a0472f237945526db1420e8b
selenium-node-docker-1 | 09:18:38.658 WARN [SessionSlot.apply] - Unable to create session
selenium-node-docker-1 | java.lang.IllegalArgumentException: non-positive contentLength: 0
selenium-node-docker-1 | at java.net.http/java.net.http.HttpRequest$BodyPublishers.fromPublisher(HttpRequest.java:539)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.jdk.JdkHttpMessages.notChunkingBodyPublisher(JdkHttpMessages.java:124)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.jdk.JdkHttpMessages.createRequest(JdkHttpMessages.java:76)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:284)
selenium-node-docker-1 | at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:55)
selenium-node-docker-1 | at org.openqa.selenium.docker.v1_41.StartContainer.apply(StartContainer.java:40)
selenium-node-docker-1 | at org.openqa.selenium.docker.v1_41.V141Docker.startContainer(V141Docker.java:115)
selenium-node-docker-1 | at org.openqa.selenium.docker.Container.start(Container.java:47)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.docker.DockerSessionFactory.apply(DockerSessionFactory.java:155)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.docker.DockerSessionFactory.apply(DockerSessionFactory.java:90)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.local.SessionSlot.apply(SessionSlot.java:147)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.local.LocalNode.newSession(LocalNode.java:379)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.NewNodeSession.execute(NewNodeSession.java:52)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route$TemplatizedRoute.handle(Route.java:192)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
selenium-node-docker-1 | at org.openqa.selenium.grid.security.RequiresSecretFilter.lambda$apply$0(RequiresSecretFilter.java:64)
selenium-node-docker-1 | at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:86)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
selenium-node-docker-1 | at org.openqa.selenium.grid.node.Node.execute(Node.java:240)
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
selenium-hub | 09:18:38.683 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "cc2027cb11afaa2d1170c39d548db3d0","eventTime": 1670059118537190489,"eventName": "Session request received by the Distributor","attributes": {"logger": "org.openqa.selenium.grid.distributor.local.LocalDistributor","request.payload": "[Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}, se:name: My simple test}]"}}
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
selenium-hub |
selenium-node-docker-1 | at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
selenium-hub | 09:18:38.684 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to create session: Could not start a new session. Could not start a new session. non-positive contentLength: 0
selenium-node-docker-1 | at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
selenium-hub | Host info: host: '5fb5bc2b290e', ip: '172.19.0.3'
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
selenium-hub | Build info: version: '4.7.0', revision: '52e3a49ea2'
selenium-node-docker-1 | at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
selenium-hub | System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.16.3-microsoft-standard-WSL2', java.version: '11.0.17'
selenium-node-docker-1 | at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
selenium-hub | Driver info: driver.version: unknown
selenium-node-docker-1 | at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
selenium-hub | Build info: version: '4.7.0', revision: '52e3a49ea2'
selenium-node-docker-1 | at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
selenium-hub | System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.10.16.3-microsoft-standard-WSL2', java.version: '11.0.17'
selenium-node-docker-1 | at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
selenium-hub | Driver info: driver.version: unknown
selenium-node-docker-1 | at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
selenium-hub | 09:18:38.685 WARN [SeleniumSpanExporter$1.lambda$export$1] - org.openqa.selenium.SessionNotCreatedException: Could not start a new session. Could not start a new session. non-positive contentLength: 0
selenium-node-docker-1 | at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
selenium-hub | Host info: host: '5fb5bc2b290e', ip: '172.19.0.3'
selenium-node-docker-1 | at java.base/java.lang.Thread.run(Thread.java:829)
selenium-hub | Build info: version: '4.7.0', revision: '52e3a49ea2'
selenium-node-docker-1 | 09:18:38.662 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "cc2027cb11afaa2d1170c39d548db3d0","eventTime": 1670059118661211153,"eventName": "Unable to create session with the driver","attributes": {"current.session.count": 0,"logger": "org.openqa.selenium.grid.node.local.LocalNode","session.request.capabilities": "Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}, se:name: My simple test}","session.request.downstreamdialect": "[W3C, OSS]"}}

[diemol]

@victortanase because the fix has not been released. Probably on Monday or Tuesday.

[jsa34]

@diemol Hello! Just encountered this issue - any plans to release today? :)