selenium icon indicating copy to clipboard operation
selenium copied to clipboard

[🐛 Bug]: Session request timeout not respected from version 4.27+ – queued sessions killed prematurely

Open sarulatha20 opened this issue 6 months ago • 7 comments

Description

From Selenium 4.27 onwards, the --session-request-timeout parameter doesn't behave as expected. Even when set explicitly (e.g., 600 seconds), queued session requests are being rejected after only 2–3 minutes. This did not occur in 4.26, which works as expected.

Reproducible Code

1.Start hub:
java -jar selenium-server-4.30.0.jar hub --session-request-timeout 600

2,Start node:
java -jar selenium-server-4.30.0.jar node --hub http://localhost:4444

3.Queue a session when no slots are available (simulate load or disconnect a node).
4.Wait 3 mins → session is rejected before 600s timeout.

Expected behavior:
The session should remain in the queue until the --session-request-timeout is reached (e.g., 600s), and only then be rejected if not handled.

Debugging Logs

java -jar /Users/saru-18276/Downloads/selenium-server-4.27.0.jar hub --session-request-timeout 600
21:37:25.142 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding
21:37:25.145 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing
21:37:25.222 INFO [BoundZmqEventBus.<init>] - XPUB binding to [binding to tcp://*:4442, advertising as tcp://[fe80:0:0:0:188b:c3ae:80e7:94b8%en0]:4442], XSUB binding to [binding to tcp://*:4443, advertising as tcp://[fe80:0:0:0:188b:c3ae:80e7:94b8%en0]:4443]
21:37:25.249 INFO [UnboundZmqEventBus.<init>] - Connecting to tcp://[fe80:0:0:0:188b:c3ae:80e7:94b8%en0]:4442 and tcp://[fe80:0:0:0:188b:c3ae:80e7:94b8%en0]:4443
21:37:25.261 INFO [UnboundZmqEventBus.<init>] - Sockets created
21:37:26.269 INFO [UnboundZmqEventBus.<init>] - Event bus ready
21:37:26.600 INFO [Hub.execute] - Started Selenium Hub 4.27.0 (revision d6e718d): http://10.15.97.132:4444
21:37:34.389 INFO [Node.<init>] - Binding additional locator mechanisms: relative
21:37:34.592 INFO [GridModel.setAvailability] - Switching Node a5a02ffd-c693-4d6d-b527-55d81601b380 (uri: http://10.15.97.132:5558) from DOWN to UP
21:37:34.592 INFO [LocalDistributor.add] - Added node a5a02ffd-c693-4d6d-b527-55d81601b380 at http://10.15.97.132:5558. Health check every 120s
21:37:43.742 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {browserName: chrome, goog:chromeOptions: {args: [--no-sandbox, --headless], extensions: []}}]
21:37:45.406 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: e7add0c1810886e1d8b73c1aab7bebc1 
 Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.69, chrome: {chromedriverVersion: 137.0.7151.68 (2989ffee9373..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:53960}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: {}, se:bidiEnabled: false, se:cdp: ws://10.15.97.132:4444/grid..., se:cdpVersion: 137.0.7151.69, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}
21:40:43.685 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "51eb5d602a6542d854b0d4fd07dd8a23","eventTime": 1749226243682504166,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "10.15.97.132:4444","http.method": "POST","http.request_content_length": "268","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.23.0 (java mac)"}}

ℹ️ Last known working version: 4.26.0

sarulatha20 avatar Jun 06 '25 16:06 sarulatha20

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

Selenium Triage Team: remember to follow the Triage Guide

selenium-ci avatar Jun 06 '25 16:06 selenium-ci

⚠️ You reported using Selenium version 4.30.0, but the latest release is 4.33.

Please verify that this issue still occurs with the latest version. If it no longer applies, you can close this issue or update your comment.

This issue will be marked "awaiting answer" and may be closed automatically if no response is received.

github-actions[bot] avatar Jun 06 '25 16:06 github-actions[bot]

Can you try to set the readTimeout longer in client code to create the RemoteWebDriver? https://www.selenium.dev/documentation/webdriver/drivers/http_client/

VietND96 avatar Jun 08 '25 20:06 VietND96

Can you try to set the readTimeout longer in client code to create the RemoteWebDriver? https://www.selenium.dev/documentation/webdriver/drivers/http_client/

Can you please clarify the purpose of setting readTimeout on the client side when creating the RemoteWebDriver? I'm currently using --session-request-timeout on the Selenium Grid node, but it doesn't seem to be working as expected. I'd like to understand why this timeout isn't being respected and how readTimeout behaves differently in this context.

sarulatha20 avatar Jun 11 '25 07:06 sarulatha20

⚠️ You reported using Selenium version 4.30.0, but the latest release is 4.33.

Please verify that this issue still occurs with the latest version. If it no longer applies, you can close this issue or update your comment.

This issue will be marked "awaiting answer" and may be closed automatically if no response is received.

Yes, I’ve tried with both version v4.30.0 and v4.33.0 but the issue still persists.

sarulatha20 avatar Jun 11 '25 07:06 sarulatha20

@sarulatha20 As soon as the server detect the client has gone away, the session request is disposed, as the session will never be used by the client (#14756). Otherwise the client would not receive the session id and the session will be terminated due to a timeout by the server after some time has passed (#14743).

Did i miss something, is there a case where this is problematic?

joerg1985 avatar Jun 11 '25 15:06 joerg1985

As soon as the server detect the client has gone away, the session request is disposed, as the session will never be used by the client (#14756). Otherwise the client would not receive the session id and the session will be terminated due to a timeout by the server after some time has passed (#14743).

@joerg1985 Although the client remains active, the session request is being terminated while still in the queue. The session is supposed to wait, as a node is starting up. I’ve explicitly set -session-request-timeout to 10 minutes, but the session gets killed within 2 to 3 minutes instead. The client has not disconnected.

This issue only occurs on versions above 4.27.

sarulatha20 avatar Jun 12 '25 05:06 sarulatha20

@sarulatha20 i have tried to reproduce the issue with version 4.32.0 without success.

The code below will start a hub / node and will try to create sessions blocking each other so the session request is stuck inside the queue. The webDriver2 is blocked for ~280s and will successfully start, the webDriver3 is blocked for more than 600s and rejected after the timeout of ~600s.

Could you try to build an example like the code below to show the issue? Or does the code below fail for you? I am running it with win 11 and jdk 21.

import java.net.URI;
import java.time.Duration;
import org.openqa.selenium.WebDriver;
import org.openqa.selenium.chrome.ChromeOptions;
import org.openqa.selenium.remote.RemoteWebDriver;
import org.openqa.selenium.remote.http.ClientConfig;

public class Main {

    public static void main(String[] args) throws Exception {
        // start servers
        org.openqa.selenium.grid.Bootstrap.main("hub --host 127.0.0.1 --port 4567 --session-request-timeout 600".split(" "));
        org.openqa.selenium.grid.Bootstrap.main("node --selenium-manager true --override-max-sessions true --max-sessions 1 --port 5555 --hub http://127.0.0.1:4567 --session-timeout 720".split(" "));

        // wait for the server to get ready
        Thread.sleep(10_000);

        // ensure the client will wait for up to 12 minutes for the session
        ClientConfig cfg = ClientConfig.defaultConfig().readTimeout(Duration.ofMinutes(12));
        ChromeOptions options = new ChromeOptions();

        // occupy the one slot we have
        WebDriver webDriver1 = new RemoteWebDriver(URI.create("http://127.0.0.1:4567/wd/hub").toURL(), options);
        System.out.println("webDriver1 started");

        // release the one slot we have after 280s
        new Thread(() -> {
            try {
                System.out.println("wait 280s to quit webDriver1");
                Thread.sleep(280_000);
            } catch (InterruptedException e) {
                System.exit(666);
            }

            System.out.println("quit webDriver1");
            webDriver1.quit();
        }).start();

        long before = System.currentTimeMillis();
        // try to occupy another slot, so the client must wait here
        WebDriver webDriver2 = RemoteWebDriver.builder()
                .oneOf(options)
                .address("http://127.0.0.1:4567/wd/hub")
                .config(cfg)
                .build();

        long after = System.currentTimeMillis();

        System.out.println("webDriver2 started after " + ((after - before) / 1000) + "s");

        long before2 = System.currentTimeMillis();
        // try to occupy another slot, so the client must wait here
        try {
            WebDriver webDriver3 = RemoteWebDriver.builder()
                    .oneOf(options)
                    .address("http://127.0.0.1:4567/wd/hub")
                    .config(cfg)
                    .build();

            // should not be reached
            System.exit(666);
        } catch (Exception e) {
            long after2 = System.currentTimeMillis();

           System.out.println("webDriver3 is rejected after " + ((after2 - before2) / 1000) + "s");
        }

        System.out.println("quit webDriver2");
        webDriver2.quit();

        // shutdown the servers
        System.exit(0);
    }
}

Console output

cd C:\Users\joerg\Documents\NetBeansProjects\some.issues; JAVA_HOME=C:\\projekte\\jdk21 cmd /c "\"C:\\projekte\\netbeans\\java\\maven\\bin\\mvn.cmd\" -Dexec.vmArgs= \"-Dexec.args=${exec.vmArgs} -classpath %classpath ${exec.mainClass} ${exec.appArgs}\" -Dexec.executable=C:\\projekte\\jdk21\\bin\\java.exe -Dexec.mainClass=some.issues.Main -Dexec.classpathScope=runtime -Dexec.appArgs= --no-transfer-progress -T 1.5C process-classes org.codehaus.mojo:exec-maven-plugin:3.1.0:exec"
Scanning for projects...

Using the MultiThreadedBuilder implementation with a thread count of 24

---------------------< com.mycompany:some.issues >----------------------
Building some.issues 1.0-SNAPSHOT
  from pom.xml
--------------------------------[ jar ]---------------------------------

--- resources:3.3.1:resources (default-resources) @ some.issues ---
skip non existing resourceDirectory C:\Users\joerg\Documents\NetBeansProjects\some.issues\src\main\resources

--- compiler:3.13.0:compile (default-compile) @ some.issues ---
Recompiling the module because of changed source code.
Compiling 1 source file with javac [debug release 21] to target\classes

--- exec:3.1.0:exec (default-cli) @ some.issues ---
21:16:15.984 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding
21:16:16.001 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing
21:16:16.334 INFO [BoundZmqEventBus.<init>] - XPUB binding to [binding to tcp://*:4442, advertising as tcp://192.168.1.25:4442], XSUB binding to [binding to tcp://*:4443, advertising as tcp://192.168.1.25:4443]
21:16:16.430 INFO [UnboundZmqEventBus.<init>] - Connecting to tcp://192.168.1.25:4442 and tcp://192.168.1.25:4443
21:16:16.477 INFO [UnboundZmqEventBus.<init>] - Sockets created
21:16:17.480 INFO [UnboundZmqEventBus.<init>] - Event bus ready
21:16:18.715 INFO [Hub.execute] - Started Selenium Hub 4.32.0 (revision d17c8aa950): http://127.0.0.1:4567
21:16:18.737 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding
21:16:18.747 INFO [UnboundZmqEventBus.<init>] - Connecting to tcp://127.0.0.1:4442 and tcp://127.0.0.1:4443
21:16:18.777 INFO [UnboundZmqEventBus.<init>] - Sockets created
21:16:19.783 INFO [UnboundZmqEventBus.<init>] - Event bus ready
21:16:19.796 INFO [NodeServer.createHandlers] - Reporting self as: http://192.168.1.25:5555
21:16:19.826 INFO [NodeOptions.getSessionFactories] - Detected 16 available processors
21:16:19.827 WARN [NodeOptions.getSessionFactories] - Overriding max recommended number of 16 concurrent sessions. Session stability and reliability might suffer!
21:16:19.827 WARN [NodeOptions.getSessionFactories] - One browser session is recommended per available processor. Safari is always limited to 1 session per host.
21:16:19.828 WARN [NodeOptions.getSessionFactories] - Overriding this value for Internet Explorer is not recommended. Issues related to parallel testing with Internet Explored won't be accepted.
21:16:19.828 WARN [NodeOptions.getSessionFactories] - Double check if enabling 'override-max-sessions' is really needed
21:16:21.033 INFO [NodeOptions.report] - Adding Chrome for {"browserName": "chrome","platformName": "Windows 11"} 1 times
21:16:21.035 INFO [NodeOptions.report] - Adding Internet Explorer for {"browserName": "internet explorer","platformName": "Windows 11"} 1 times
21:16:21.036 INFO [NodeOptions.report] - Adding Firefox for {"browserName": "firefox","platformName": "Windows 11"} 1 times
21:16:21.038 INFO [NodeOptions.report] - Adding Edge for {"browserName": "MicrosoftEdge","platformName": "Windows 11"} 1 times
21:16:21.059 INFO [Node.<init>] - Binding additional locator mechanisms: relative
21:16:21.151 INFO [NodeServer$2.start] - Starting registration process for Node http://192.168.1.25:5555
21:16:21.152 INFO [NodeServer.execute] - Started Selenium node 4.32.0 (revision d17c8aa950): http://192.168.1.25:5555
21:16:21.173 INFO [NodeServer$2.lambda$start$2] - Sending registration event...
21:16:21.200 INFO [Node.<init>] - Binding additional locator mechanisms: relative
21:16:21.772 INFO [GridModel.setAvailability] - Switching Node 027513a5-96e5-4805-ab1c-e3a592c9ad7c (uri: http://192.168.1.25:5555) from DOWN to UP
21:16:21.772 INFO [LocalDistributor.add] - Added node 027513a5-96e5-4805-ab1c-e3a592c9ad7c at http://192.168.1.25:5555. Health check every 120s
21:16:21.776 INFO [NodeServer.lambda$createHandlers$2] - Node has been added
21:16:31.277 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}}]
21:16:34.063 INFO [LocalNode.newSession] - Session created by the Node. Id: 383e74983462f5a8d0b2533a5fc1ac32, Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.119, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: C:\Users\joerg\AppData\Loca...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:52433}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: Windows 11, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://127.0.0.1:4567/session..., se:cdpVersion: 137.0.7151.119, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}
21:16:34.084 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 383e74983462f5a8d0b2533a5fc1ac32 
 Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.119, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: C:\Users\joerg\AppData\Loca...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:52433}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: Windows 11, proxy: {}, se:bidiEnabled: false, se:cdp: ws://127.0.0.1:4567/session..., se:cdpVersion: 137.0.7151.119, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}
webDriver1 started
wait 280s to quit webDriver1
quit webDriver1
21:21:14.683 INFO [LocalNode.stopTimedOutSession] - Session id 383e74983462f5a8d0b2533a5fc1ac32 is stopping on demand...
21:21:14.684 INFO [SessionSlot.stop] - Stopping session 383e74983462f5a8d0b2533a5fc1ac32
21:21:14.687 INFO [LocalSessionMap.remove] - Deleted session from local Session Map, Id: 383e74983462f5a8d0b2533a5fc1ac32
21:21:14.687 INFO [GridModel.release] - Releasing slot for session id 383e74983462f5a8d0b2533a5fc1ac32
21:21:14.706 INFO [LocalDistributor.newSession] - Session request received by the Distributor: 
 [Capabilities {browserName: chrome, goog:chromeOptions: {args: [], extensions: []}}]
21:21:15.699 INFO [LocalNode.newSession] - Session created by the Node. Id: 7641cde248ea129f52dcaf37ddc21253, Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.119, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: C:\Users\joerg\AppData\Loca...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:65447}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: Windows 11, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://127.0.0.1:4567/session..., se:cdpVersion: 137.0.7151.119, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}
21:21:15.709 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 7641cde248ea129f52dcaf37ddc21253 
 Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.119, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: C:\Users\joerg\AppData\Loca...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:65447}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: Windows 11, proxy: {}, se:bidiEnabled: false, se:cdp: ws://127.0.0.1:4567/session..., se:cdpVersion: 137.0.7151.119, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}
21:21:15.963 WARN [CdpVersionFinder.findNearestMatch] - Unable to find an exact match for CDP version 137, returning the closest version; found: 136; Please update to a Selenium version that supports CDP version 137
21:21:16.001 INFO [ProxyNodeWebsockets.createWsEndPoint] - Establishing connection to ws://localhost:65447/devtools/browser/b86f4ab9-9fff-4e93-b67a-193d14ddfcba
webDriver2 started after 282s
21:31:16.423 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "6896533e13d4e5b38e32714ef58642d0","eventTime": 1750275076419005400,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "127.0.0.1:4567","http.method": "POST","http.request_content_length": "243","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.32.0 (java windows)"}}

webDriver3 is rejected after 600s
quit webDriver2
21:31:16.884 INFO [LocalNode.stopTimedOutSession] - Session id 7641cde248ea129f52dcaf37ddc21253 is stopping on demand...
21:31:16.885 INFO [SessionSlot.stop] - Stopping session 7641cde248ea129f52dcaf37ddc21253
21:31:16.886 INFO [GridModel.release] - Releasing slot for session id 7641cde248ea129f52dcaf37ddc21253
21:31:16.887 INFO [LocalSessionMap.remove] - Deleted session from local Session Map, Id: 7641cde248ea129f52dcaf37ddc21253
------------------------------------------------------------------------
BUILD SUCCESS
------------------------------------------------------------------------
Total time:  15:05 min (Wall Clock)
Finished at: 2025-06-18T21:31:17+02:00
------------------------------------------------------------------------

joerg1985 avatar Jun 18 '25 19:06 joerg1985

`import java.net.URL; import java.time.Duration; import java.time.Instant; import java.util.concurrent.*; import java.util.logging.Level; import java.util.logging.Logger;

import org.openqa.selenium.Capabilities; import org.openqa.selenium.chrome.ChromeOptions; import org.openqa.selenium.remote.RemoteWebDriver;

public class LongRunningSessionTest { private static final Logger LOGGER = Logger.getLogger(LongRunningSessionTest.class.getName()); private static final Duration RUN_DURATION = Duration.ofMinutes(5); private static final String TARGET_URL = "https://www.example.com"; private static final int NUM_SESSIONS = 2;

public static void main(String[] args) {
    ExecutorService executor = Executors.newFixedThreadPool(NUM_SESSIONS);
    CountDownLatch latch = new CountDownLatch(NUM_SESSIONS);
    for (int i = 1; i <= NUM_SESSIONS; i++) {
        final int sessionId = i;
        executor.submit(() -> {
            runSession(sessionId);
            latch.countDown();
        });
    }

    try {
        latch.await();
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
    } finally {
        executor.shutdown();
    }

    LOGGER.info("All sessions completed.");
}

private static void runSession(int sessionId) {
    RemoteWebDriver driver = null;
    try {
        LOGGER.info("[Session " + sessionId + "] Initializing browser...");
        ChromeOptions options = new ChromeOptions();
        options.addArguments("--no-sandbox");
        options.addArguments("--headless");

        driver = new RemoteWebDriver(new URL("http://{HUB_IP}:4444/wd/hub"), options);
        Capabilities caps = driver.getCapabilities();
        LOGGER.info("[Session " + sessionId + "] Browser Version: " + caps.getBrowserVersion());

        Instant start = Instant.now();
        Instant end = start.plus(RUN_DURATION);
        int iteration = 1;

        while (Instant.now().isBefore(end)) {
            driver.get(TARGET_URL);
            LOGGER.info("[Session " + sessionId + "] Iteration " + iteration + " - URL Loaded: " + driver.getCurrentUrl());
            Thread.sleep(2000);
            iteration++;
        }

        LOGGER.info("[Session " + sessionId + "] Completed all iterations.");
    } catch (Exception e) {
        LOGGER.log(Level.SEVERE, "[Session " + sessionId + "] Error occurred: ", e);
    } finally {
        if (driver != null) {
            try {
                driver.quit();
            } catch (Exception ignored) {}
            LOGGER.info("[Session " + sessionId + "] Driver closed.");
        }
    }
}

} `

Hub Startup Command:

java -jar selenium-server-4.33.0.jar hub --session-request-timeout 600

Node Startup Command

java -jar selenium-server-4.33.0.jar node --port 5558 --hub http://{hubIP}:4444/grid/register --max-sessions 1

I’ve set --session-request-timeout to 600 seconds (10 minutes), expecting the session queue to retain requests for that duration.

Test Scenario: I launched 2 parallel browser sessions using a simple Java test (only one session allowed at a time due to --max-sessions 1).

The second session was expected to wait in the queue for up to 10 minutes.

Hub log:

11:25:04.534 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding 11:25:04.537 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing 11:25:04.603 INFO [BoundZmqEventBus.] - XPUB binding to [binding to tcp://:4442, advertising as tcp://[fe80:0:0:0:832:5291:946b:2e6b%en0]:4442], XSUB binding to [binding to tcp://:4443, advertising as tcp://[fe80:0:0:0:832:5291:946b:2e6b%en0]:4443] 11:25:04.630 INFO [UnboundZmqEventBus.] - Connecting to tcp://[fe80:0:0:0:832:5291:946b:2e6b%en0]:4442 and tcp://[fe80:0:0:0:832:5291:946b:2e6b%en0]:4443 11:25:04.641 INFO [UnboundZmqEventBus.] - Sockets created 11:25:05.647 INFO [UnboundZmqEventBus.] - Event bus ready 11:25:05.954 INFO [Hub.execute] - Started Selenium Hub 4.33.0 (revision 2c6aaad03a): http://{IP}:4444 11:25:14.753 INFO [Node.] - Binding additional locator mechanisms: relative 11:25:14.942 INFO [GridModel.setAvailability] - Switching Node 71d87961-9fb2-4cad-96c1-9b0177317d11 (uri: http://{IP}:5558) from DOWN to UP 11:25:14.942 INFO [LocalDistributor.add] - Added node 71d87961-9fb2-4cad-96c1-9b0177317d11 at http://{IP}:5558. Health check every 120s 11:25:43.296 INFO [LocalDistributor.newSession] - Session request received by the Distributor: [Capabilities {browserName: chrome, goog:chromeOptions: {args: [--no-sandbox, --headless], extensions: []}}] 11:25:46.705 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 015798898e2970530cdc27ca4cddee68 Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60561}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: {}, se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true} 11:25:49.518 INFO [LocalSessionMap.remove] - Deleted session from local Session Map, Id: 015798898e2970530cdc27ca4cddee68 11:25:49.518 INFO [GridModel.release] - Releasing slot for session id 015798898e2970530cdc27ca4cddee68 11:25:49.530 INFO [LocalDistributor.newSession] - Session request received by the Distributor: [Capabilities {browserName: chrome, goog:chromeOptions: {args: [--no-sandbox, --headless], extensions: []}}] 11:25:50.294 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 8d6cf434c7b97a5945c9ed2eb7fb0e3f Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60599}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: {}, se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true} 11:25:52.567 INFO [GridModel.release] - Releasing slot for session id 8d6cf434c7b97a5945c9ed2eb7fb0e3f 11:25:52.567 INFO [LocalSessionMap.remove] - Deleted session from local Session Map, Id: 8d6cf434c7b97a5945c9ed2eb7fb0e3f 11:26:15.421 INFO [LocalDistributor.newSession] - Session request received by the Distributor: [Capabilities {browserName: chrome, goog:chromeOptions: {args: [--no-sandbox, --headless], extensions: []}}] 11:26:16.432 INFO [LocalDistributor.newSession] - Session created by the Distributor. Id: 6f43f60404dd869a4378da880ccc733a Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60686}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: {}, se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}

11:29:15.421 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "62162e625643ac72ace5d7499e4e3a34","eventTime": 1751003955418025875,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "10.15.97.132:4444","http.method": "POST","http.request_content_length": "268","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.23.0 (java mac)"}}

11:31:17.153 INFO [GridModel.release] - Releasing slot for session id 6f43f60404dd869a4378da880ccc733a 11:31:17.153 INFO [LocalSessionMap.remove] - Deleted session from local Session Map, Id: 6f43f60404dd869a4378da880ccc733a

Node Logs:

11:25:12.875 INFO [LoggingOptions.configureLogEncoding] - Using the system default encoding 11:25:12.877 INFO [OpenTelemetryTracer.createTracer] - Using OpenTelemetry for tracing 11:25:12.933 INFO [UnboundZmqEventBus.] - Connecting to tcp://{IP}:4442 and tcp://{IP}:4443 11:25:12.954 INFO [UnboundZmqEventBus.] - Sockets created 11:25:13.960 INFO [UnboundZmqEventBus.] - Event bus ready 11:25:14.040 INFO [NodeServer.createHandlers] - Reporting self as: http://{IP} 11:25:14.055 INFO [NodeOptions.getSessionFactories] - Detected 8 available processors 11:25:14.055 INFO [NodeOptions.discoverDrivers] - Looking for existing drivers on the PATH. 11:25:14.056 INFO [NodeOptions.discoverDrivers] - Add '--selenium-manager true' to the startup command to setup drivers automatically. 11:25:14.376 WARN [SeleniumManager.lambda$runCommand$1] - Unable to discover proper msedgedriver version in offline mode 11:25:14.500 WARN [SeleniumManager.lambda$runCommand$1] - Exception managing firefox: Unable to discover proper geckodriver version in offline mode 11:25:14.618 WARN [SeleniumManager.lambda$runCommand$1] - Unable to download safaridriver in offline mode 11:25:14.634 INFO [NodeOptions.report] - Adding Chrome for {"browserName": "chrome","platformName": "mac"} 1 times 11:25:14.634 INFO [NodeOptions.report] - Adding Edge for {"browserName": "MicrosoftEdge","platformName": "mac"} 1 times 11:25:14.635 INFO [NodeOptions.report] - Adding Firefox for {"browserName": "firefox","platformName": "mac"} 1 times 11:25:14.635 INFO [NodeOptions.report] - Adding Safari for {"browserName": "safari","platformName": "mac"} 1 times 11:25:14.636 INFO [NodeOptions.report] - Adding Safari Technology Preview for {"browserName": "Safari Technology Preview","platformName": "mac"} 1 times 11:25:14.658 INFO [Node.] - Binding additional locator mechanisms: relative 11:25:14.735 INFO [NodeServer$2.start] - Starting registration process for Node http://{IP}:5558 11:25:14.736 INFO [NodeServer.execute] - Started Selenium node 4.33.0 (revision 2c6aaad03a): http://{IP}:5558 11:25:14.744 INFO [NodeServer$2.lambda$start$2] - Sending registration event... 11:25:14.945 INFO [NodeServer.lambda$createHandlers$2] - Node has been added 11:25:46.574 INFO [LocalNode.newSession] - Session created by the Node. Id: 015798898e2970530cdc27ca4cddee68, Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60561}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true} 11:25:49.515 INFO [LocalNode.stopTimedOutSession] - Session id 015798898e2970530cdc27ca4cddee68 is stopping on demand... 11:25:49.516 INFO [SessionSlot.stop] - Stopping session 015798898e2970530cdc27ca4cddee68 11:25:50.264 INFO [LocalNode.newSession] - Session created by the Node. Id: 8d6cf434c7b97a5945c9ed2eb7fb0e3f, Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60599}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true} 11:25:52.565 INFO [LocalNode.stopTimedOutSession] - Session id 8d6cf434c7b97a5945c9ed2eb7fb0e3f is stopping on demand... 11:25:52.565 INFO [SessionSlot.stop] - Stopping session 8d6cf434c7b97a5945c9ed2eb7fb0e3f 11:26:16.401 INFO [LocalNode.newSession] - Session created by the Node. Id: 6f43f60404dd869a4378da880ccc733a, Caps: Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 137.0.7151.120, chrome: {chromedriverVersion: 137.0.7151.119 (e0ac9d12dff..., userDataDir: /var/folders/l4/xrzxmb8n6jn...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60686}, networkConnectionEnabled: false, pageLoadStrategy: normal, platformName: mac, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://{IP}:4444/grid..., se:cdpVersion: 137.0.7151.120, setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true}

11:31:17.151 INFO [LocalNode.stopTimedOutSession] - Session id 6f43f60404dd869a4378da880ccc733a is stopping on demand... 11:31:17.152 INFO [SessionSlot.stop] - Stopping session 6f43f60404dd869a4378da880ccc733a

However, the hub log shows:

11:25:49.530 → Session request received.

11:26:15.421 → Another session request received (while first one was active).

11:29:15.421 → The queued session is rejected with HTTP 500:

11:29:15.421 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "62162e625643ac72ace5d7499e4e3a34","eventTime": 1751003955418025875,"eventName": "HTTP request execution complete","attributes": {"http.client_ip": "127.0.0.1","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "10.15.97.132:4444","http.method": "POST","http.request_content_length": "268","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.23.0 (java mac)"}}

The time between receiving the second session (11:26:15.421) and the rejection (11:29:15.421) is ~3 minutes, even though the timeout is configured as 10 minutes.

Expected Behavior: The queued session should wait for up to 10 minutes before timing out or getting rejected.

Observation: This could indicate that either:

1.The session-request-timeout is not being honored.

2.The timer is starting earlier than expected.

3.There's an internal timeout overriding the expected queue timeout.

sarulatha20 avatar Jun 27 '25 06:06 sarulatha20

@sarulatha20 have a look at the exception on the client site, it is caused by a timeout. So the client does timeout first, after that the server detects the client is gone and rejects the session request to avoid starting a "dead" session. So increasing the client timeout will fix your issue.

joerg1985 avatar Jun 28 '25 10:06 joerg1985

The logs I shared are only from the hub and node; I haven’t included any client-side logs. So how can it be concluded that this is a client timeout? If that were the case, the issue should occur consistently across all Selenium versions. However, the same code works without any issues on Selenium version 4.26. If it were truly a client-side timeout, wouldn’t the problem be version-independent?

Also, please review the hub log—specifically, check the session request received time and the rejection time. I’ve configured the session-request-timeout to 5 minutes, but the request is getting rejected from the queue in just 3 minutes. @joerg1985

sarulatha20 avatar Jun 30 '25 05:06 sarulatha20

Can you refer the way to set readTimeout at client? https://www.selenium.dev/documentation/webdriver/drivers/http_client/

VietND96 avatar Jun 30 '25 11:06 VietND96

@sarulatha20 i did run the code you have provided with 4.32.0 and 4.26.0, both show the same error in the client logs. This is the way i have looked into these client logs, so i guess you should see the same client error?

The 4.26.0 grid did ignore the client to fail and did start the session any way, so you won't see any error here. The 4.32.0 grid does detect the client did fail, so you can see an error inside the server log.

Did you try to set a higher client timeout?

joerg1985 avatar Jun 30 '25 15:06 joerg1985

I’m still trying to understand what’s causing the behavior difference between 4.26.0 and 4.32.0 in more detail.

Could you please share:

1.The client logs

2.The hub logs, and

3.The node logs

This will help me correlate what I’m seeing on my side and verify if the same failure pattern is happening across setups.

sarulatha20 avatar Jul 01 '25 05:07 sarulatha20

@sarulatha20 here you go:

client.txt

hub.txt

node.txt

joerg1985 avatar Jul 16 '25 19:07 joerg1985

This issue was closed because we did not receive any additional information after 14 days.

github-actions[bot] avatar Aug 08 '25 10:08 github-actions[bot]

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

github-actions[bot] avatar Sep 07 '25 22:09 github-actions[bot]