search

SeleniumHQ / docker-selenium

Provides a simple way to run Selenium Grid with Chrome, Firefox, and Edge using Docker, making it easier to perform browser automation
http://www.selenium.dev/docker-selenium/
Other
7.86k stars 2.51k forks source link

[🐛 Bug]: Dynamic Grid fails to create standalone browser containers 4.7.2-20221219 #1766

Closed itkhanz closed 1 year ago

itkhanz commented 1 year ago

What happened?

Hi, I am trying to setup Docker Dynamic Grid. The node-docker and selenium-hub is created successfully but when I execute my tests, all the tests fail with timeout because the Dynamic grid does not start a new standalone container based on session request for corresponding browser.

This is the error in node-docker logs and seems it probably has to do something with content length or capabilities. I have total of 9 tests with 3 tests for each browser (edge, chrome and firefox) and i get the same error for each session request.

WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "828df50fadd125fd657b29ce777edf82","eventTime": 1673221222249126100,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "503","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}

This is my docker-compose-v3-dynamic-grid.yml in the project root

version: "3"
services:
  node-docker:
    image: selenium/node-docker:4.7.2-20221219
    volumes:
      - ./assets/test-recordings:/opt/selenium/assets
      - ./src/test/resources/framework/selenium-grid-config/dynamic-grid-config.toml:/opt/bin/config.toml
    depends_on:
      - selenium-hub
    environment:
      - SE_EVENT_BUS_HOST=selenium-hub
      - SE_EVENT_BUS_PUBLISH_PORT=4442
      - SE_EVENT_BUS_SUBSCRIBE_PORT=4443

  selenium-hub:
    image: selenium/hub:4.7.2-20221219
    container_name: selenium-hub
    ports:
      - "4442:4442"
      - "4443:4443"
      - "4444:4444"

and this is my dynamic-grid-config.toml

[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.7.2-20221219", "{\"browserName\": \"firefox\"}",
    "selenium/standalone-chrome:4.7.2-20221219", "{\"browserName\": \"chrome\"}",
    "selenium/standalone-edge:4.7.2-20221219", "{\"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.
url = "http://host.docker.internal:2375"
# Docker image used for video recording
video-image = "selenium/video:ffmpeg-4.3.1-20221219"

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

I also exposed the daemon on tcp://localhost:235 without TLS in Docker Desktop.

This is how I am initializing the remote webdriver for each of the browsers with switch case statements e.g. for MicrosoftEdge

EdgeOptions options = new EdgeOptions();
options.setCapability("platformName", platform);
options.setCapability("se:recordVideo", true);
driver = new RemoteWebDriver(new URL("http://localhost:4444/"), options);

The Grid and Node is setup but the docker does not creates new containers based on session requests dynamically.

dynamic-grid-overview

The tests fail after a timeout and the terminal logs show following ERROR for each of the test:

[ERROR]   BaseTestNGRunnerTest.runScenario » SessionNotCreated Could not start a new session. Possible causes are invalid address of the remote server or browser start-up failure. 
Host info: host: 'DESKTOP-4JJ8P4R', ip: '192.168.50.152'
Build info: version: '4.6.0', revision: '79f1c02ae20'
System info: os.name: 'Windows 10', os.arch: 'amd64', os.version: '10.0', java.version: '17.0.5'
Driver info: org.openqa.selenium.remote.RemoteWebDriver
Command: [null, newSession {capabilities=[Capabilities {browserName: MicrosoftEdge, ms:edgeOptions: {args: [], extensions: []}, platformName: LINUX, se:recordVideo: true}], desiredCapabilities=Capabilities {browserName: MicrosoftEdge, ms:edgeOptions: {args: [], exte
nsions: []}, platformName: LINUX, se:recordVideo: true}}]
Capabilities {}

Command used to start Selenium Grid with Docker

docker-compose -f docker-compose-v3-dynamic-grid.yml up -d

Relevant log output

Below are the error logs and my dynamic-grid yml file as well as config.toml

selenium-hub

2023-01-09 00:34:27 2023-01-08 23:34:27,677 INFO Included extra file "/etc/supervisor/conf.d/selenium-grid-hub.conf" during parsing
2023-01-09 00:34:27 2023-01-08 23:34:27,689 INFO RPC interface 'supervisor' initialized
2023-01-09 00:34:27 2023-01-08 23:34:27,689 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2023-01-09 00:34:27 2023-01-08 23:34:27,690 INFO supervisord started with pid 9
2023-01-09 00:34:28 2023-01-08 23:34:28,694 INFO spawned: 'selenium-grid-hub' with pid 11
2023-01-09 00:34:28 Tracing is disabled
2023-01-09 00:34:28 2023-01-08 23:34:28,704 INFO success: selenium-grid-hub entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2023-01-09 00:34:30 23:34:30.175 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding
2023-01-09 00:34:30 23:34:30.189 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing
2023-01-09 00:34:30 23:34:30.459 INFO [BoundZmqEventBus.<init>] - XPUB binding to [binding to tcp://*:4442, advertising as tcp://172.24.0.2:4442], XSUB binding to [binding to tcp://*:4443, advertising as tcp://172.24.0.2:4443]
2023-01-09 00:34:30 23:34:30.777 INFO [UnboundZmqEventBus.<init>] - Connecting to tcp://172.24.0.2:4442 and tcp://172.24.0.2:4443
2023-01-09 00:34:30 23:34:30.896 INFO [UnboundZmqEventBus.<init>] - Sockets created
2023-01-09 00:34:31 23:34:31.901 INFO [UnboundZmqEventBus.<init>] - Event bus ready
2023-01-09 00:34:34 23:34:34.400 INFO [Hub.execute] - Started Selenium Hub 4.7.2 (revision 4d4020c3b7): http://172.24.0.2:4444
2023-01-09 00:34:37 23:34:37.214 INFO [Node.<init>] - Binding additional locator mechanisms: relative, id, name
2023-01-09 00:34:38 23:34:38.236 INFO [GridModel.setAvailability] - Switching Node f34c8932-826b-4e0f-9671-dd355d2e0549 (uri: http://172.24.0.3:5555) from DOWN to UP
2023-01-09 00:34:38 23:34:38.239 INFO [LocalDistributor.add] - Added node f34c8932-826b-4e0f-9671-dd355d2e0549 at http://172.24.0.3:5555. Health check every 120s
2023-01-09 00:40:22 23:40:22.245 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "828df50fadd125fd657b29ce777edf82","eventTime": 1673221222249126100,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "503","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.253 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "9bacf15e28cbe4113d08c2a205f8b9e4","eventTime": 1673221222257051100,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "487","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.279 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "d72f78252b083c8a3fc5364b8fdc862d","eventTime": 1673221222282610000,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "503","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.248 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "7f78cd1adba8835e69b0a759deb4000f","eventTime": 1673221222251986800,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "493","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.241 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "49b1423720f3f55107fa1b6701f02fb4","eventTime": 1673221222245418500,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "493","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.302 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "bcfabe2ab36dc126db910ba08e55d795","eventTime": 1673221222306281500,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "493","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.292 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "25a879dea81afd53fa9610f1fd62ad91","eventTime": 1673221222295369800,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "487","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.313 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "5a3052c7d98f9ba4cb40265f98fc5db6","eventTime": 1673221222317207900,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "487","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 
2023-01-09 00:40:22 23:40:22.261 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "84ac98f3cbb65e082edb9d008eb52d8a","eventTime": 1673221222264895800,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "localhost:4444","http.method": "POST","http.request_content_length": "503","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.6.0 (java windows)"}}
2023-01-09 00:40:22 

Node

2023-01-09 00:34:29 2023-01-08 23:34:29,788 INFO Included extra file "/etc/supervisor/conf.d/selenium-grid-docker.conf" during parsing
2023-01-09 00:34:29 2023-01-08 23:34:29,806 INFO RPC interface 'supervisor' initialized
2023-01-09 00:34:29 2023-01-08 23:34:29,806 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2023-01-09 00:34:29 2023-01-08 23:34:29,807 INFO supervisord started with pid 8
2023-01-09 00:34:30 2023-01-08 23:34:30,811 INFO spawned: 'socat' with pid 10
2023-01-09 00:34:30 2023-01-08 23:34:30,815 INFO spawned: 'selenium-grid-docker' with pid 11
2023-01-09 00:34:30 2023-01-08 23:34:30,840 INFO success: socat entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2023-01-09 00:34:30 2023-01-08 23:34:30,841 INFO success: selenium-grid-docker entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2023-01-09 00:34:30 2023-01-08 23:34:30,842 INFO exited: socat (exit status 0; expected)
2023-01-09 00:34:30 Starting Selenium Grid Node Docker...
2023-01-09 00:34:30 Tracing is disabled
2023-01-09 00:34:32 23:34:32.359 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding
2023-01-09 00:34:32 23:34:32.391 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing
2023-01-09 00:34:33 23:34:33.053 INFO [UnboundZmqEventBus.<init>] - Connecting to tcp://selenium-hub:4442 and tcp://selenium-hub:4443
2023-01-09 00:34:33 23:34:33.308 INFO [UnboundZmqEventBus.<init>] - Sockets created
2023-01-09 00:34:34 23:34:34.314 INFO [UnboundZmqEventBus.<init>] - Event bus ready
2023-01-09 00:34:34 23:34:34.762 INFO [NodeServer.createHandlers] - Reporting self as: http://172.24.0.3:5555
2023-01-09 00:34:34 23:34:34.815 INFO [NodeOptions.getSessionFactories] - Detected 4 available processors
2023-01-09 00:34:35 23:34:35.921 INFO [V141Docker.isContainerPresent] - Checking if container is present: dbd87025aeca
2023-01-09 00:34:36 23:34:36.038 INFO [Docker.getImage] - Obtaining image: selenium/standalone-chrome:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.039 INFO [Docker.getImage] - Obtaining image: selenium/standalone-firefox:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.036 INFO [Docker.getImage] - Obtaining image: selenium/standalone-edge:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.046 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-edge', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.046 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-firefox', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.046 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-chrome', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.150 INFO [Docker.getImage] - Obtaining image: selenium/video:ffmpeg-4.3.1-20221219
2023-01-09 00:34:36 23:34:36.151 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/video', tag='ffmpeg-4.3.1-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.191 INFO [Docker.getImage] - Obtaining image: selenium/video:ffmpeg-4.3.1-20221219
2023-01-09 00:34:36 23:34:36.191 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/video', tag='ffmpeg-4.3.1-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.236 INFO [Docker.getImage] - Obtaining image: selenium/standalone-edge:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.237 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-edge', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.289 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: MicrosoftEdge} to docker image selenium/standalone-edge:4.7.2-20221219 4 times
2023-01-09 00:34:36 23:34:36.290 INFO [Docker.getImage] - Obtaining image: selenium/standalone-chrome:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.291 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-chrome', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.338 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: chrome} to docker image selenium/standalone-chrome:4.7.2-20221219 4 times
2023-01-09 00:34:36 23:34:36.339 INFO [Docker.getImage] - Obtaining image: selenium/standalone-firefox:4.7.2-20221219
2023-01-09 00:34:36 23:34:36.343 INFO [V141Docker.getImage] - Listing local images: Reference{domain='docker.io', name='selenium/standalone-firefox', tag='4.7.2-20221219', digest='null'}
2023-01-09 00:34:36 23:34:36.382 INFO [DockerOptions.lambda$getDockerSessionFactories$1] - Mapping Capabilities {browserName: firefox} to docker image selenium/standalone-firefox:4.7.2-20221219 4 times
2023-01-09 00:34:36 23:34:36.482 INFO [Node.<init>] - Binding additional locator mechanisms: relative, name, id
2023-01-09 00:34:36 23:34:36.965 INFO [NodeServer$1.start] - Starting registration process for Node http://172.24.0.3:5555
2023-01-09 00:34:36 23:34:36.968 INFO [NodeServer.execute] - Started Selenium node 4.7.2 (revision 4d4020c3b7): http://172.24.0.3:5555
2023-01-09 00:34:37 23:34:37.024 INFO [NodeServer$1.lambda$start$1] - Sending registration event...
2023-01-09 00:34:38 23:34:38.254 INFO [NodeServer.lambda$createHandlers$2] - Node has been added

Operating System

Windows 10

Docker Selenium version (tag)

4.7.2-20221219

diemol commented 1 year ago

This happens because you are sending a session request with a platformName but the configured stereotype does not have one, so the Distributor cannot match the request to a Node. You should be having a message saying something related to that in the log.

github-actions[bot] commented 9 months ago

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.