Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[🐛 Bug]: Timeout set to 16 minutes, but always fails with timeout after 9 minutes #14446

Open
codex70 opened this issue Aug 28, 2024 · 9 comments
Open

[🐛 Bug]: Timeout set to 16 minutes, but always fails with timeout after 9 minutes #14446

codex70 opened this issue Aug 28, 2024 · 9 comments
Labels
I-defect needs-triaging

Comments

@codex70
Copy link

codex70 commented Aug 28, 2024 •
edited
Loading

What happened?

This is similar to the problem at #9314. I am trying to test a report which takes around 12 minutes to run. I am using selenium hub in docker with google browser. The tests are run using TestNG and Cucumber.

Originally I was seeing the same 3 minute timeout as described in the other issue, but I've implemented the code shown in the page, and now see a different timeout issue after 9 minutes (it is always exactly 9 minutes). The timeout also seems to block the driver from quitting and stopping for a significant amount of time (around a further 13 minutes). After this, I need to restart the docker container in order to connect again to the remote web driver.

How can we reproduce the issue?

Run selenium in docker with docker compose:
version: "3"
services:
  chrome:
    image: selenium/node-chrome:latest
    shm_size: 2gb
    depends_on:
      - selenium-hub
    environment:
      - SE_EVENT_BUS_HOST=selenium-hub
      - SE_EVENT_BUS_PUBLISH_PORT=4442
      - SE_EVENT_BUS_SUBSCRIBE_PORT=4443

  edge:
    image: selenium/node-edge:latest
    shm_size: 2gb
    depends_on:
      - selenium-hub
    environment:
      - SE_EVENT_BUS_HOST=selenium-hub
      - SE_EVENT_BUS_PUBLISH_PORT=4442
      - SE_EVENT_BUS_SUBSCRIBE_PORT=4443

  firefox:
    image: selenium/node-firefox:latest
    shm_size: 2gb
    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:latest
    container_name: selenium-hub
    ports:
      - "4442:4442"
      - "4443:4443"
      - "4444:4444"


Create the "SetTimeout" class:
/**
 * Reference: https://github.com/SeleniumHQ/selenium/issues/9314
 */
public class SetTimeout {

    public static final Duration clientTimeout = Duration.ofMinutes(16);
    public static final Duration defaultTimeout = Duration.ofMillis(960000);
    ChromeDriverService chromeDriverService;

    private static ChromeOptions getChromeOptions() {
        ChromeOptions options = new ChromeOptions();

        //remove unexepectedalertexceptions
        options.addArguments("--unexpectedAlertBehaviour=dismiss", "--silent", "--blink-settings=imagesEnabled=false", "--disable-blink-features", "--disable-blink-features=AutomationControlled", "--disable-gpu", "--no-sandbox", "--window-size=1920,1200", "--ignore-certificate-errors", "--disable-application-cache");

        // no downloads
        Map<String, Object> chromePrefs = new HashMap<String, Object>();
        chromePrefs.put("download_restrictions", 3);
        options.setExperimentalOption("prefs", chromePrefs);
        return options;
    }

    public ChromeDriverService getChromeDriverService() {
        return chromeDriverService;
    }

    public RemoteWebDriver createDriver(URL url) throws Exception {

        RemoteWebDriver driver;

        ChromeOptions options = getChromeOptions();

        LoggingPreferences logPrefs = new LoggingPreferences();
        logPrefs.enable(LogType.PERFORMANCE, Level.ALL);
        options.setCapability("goog:loggingPrefs", logPrefs);
        options.setPageLoadStrategy(PageLoadStrategy.EAGER);

        chromeDriverService = new ChromeDriverService.Builder().withLogOutput(System.out).build();
        chromeDriverService.start();

        ClientConfig config = ClientConfig.defaultConfig().connectionTimeout(clientTimeout)
                .readTimeout(clientTimeout).baseUrl(url);
        Tracer tracer = OpenTelemetryTracer.getInstance();
        CommandExecutor executor = new HttpCommandExecutor(
                buildChromiumCommandMappings("goog"),
                config,
                new TracedHttpClient.Factory(tracer, HttpClient.Factory.createDefault()));

        driver = new RemoteWebDriver(executor, options);

        //Inject Core Web Vitals scripts
        Map<String, Object> parameters = new HashMap<String, Object>();
        parameters.put("source", "var vitalsCLS = 'unset';\n" +
                "function logCLS({value}) {\n" +
                "  \tvitalsCLS = value.toString();\n" +
                "  \tconsole.log('CLS: ' + vitalsCLS);\n" +
                "}\n" +
                "\n" +
                "var vitalsFID = 'unset';\n" +
                "function logFID({value}) {\n" +
                "  \tvitalsFID = value.toString();\n" +
                "  \tconsole.log('FID: ' + vitalsFID);\n" +
                "}\n" +
                "\n" +
                "var vitalsLCP = 'unset';\n" +
                "function logLCP({value}) {\n" +
                "  \tvitalsLCP = value.toString();\n" +
                "  \tconsole.log('LCP: ' + vitalsLCP);\n" +
                "}\n" +
                "\n" +
                "window.onload = function() {\n" +
                "\t\n" +
                "\tvar script = document.createElement('script');\n" +
                "\tscript.src = 'https://unpkg.com/web-vitals';\n" +
                "  \tscript.onload = function() {\n" +
                "  \t\n" +
                "    // When loading `web-vitals` using a classic script, all the public\n" +
                "    // methods can be found on the `webVitals` global namespace.\n" +
                "\twebVitals.getCLS(logCLS, true); \n" +
                "    webVitals.getFID(logFID, true); \n" +
                "    webVitals.getLCP(logLCP, true); \n" +
                "  \n" +
                "  }\n" +
                "\n" +
                "  document.body.appendChild(script);\n" +
                "\n" +
                "} ");

        Command addScriptCommand = new Command(driver.getSessionId(), ChromiumDriverCommand.EXECUTE_CDP_COMMAND, ImmutableMap.of("cmd", "Page.addScriptToEvaluateOnNewDocument", "params", parameters));
        driver.getCommandExecutor().execute(addScriptCommand);

        //Stop any unwanted downloading of *.pdf *.crdownload et al. files
        parameters = new HashMap<String, Object>();
        parameters.put("behavior", "deny");

        Command setDownloadBehaviorCommand = new Command(driver.getSessionId(), ChromiumDriverCommand.EXECUTE_CDP_COMMAND, ImmutableMap.of("cmd", "Browser.setDownloadBehavior", "params", parameters));
        driver.getCommandExecutor().execute(setDownloadBehaviorCommand);
        // driver.executeCdpCommand("Browser.setDownloadBehavior", parameters);

        WebDriver.Timeouts pageLoadTimeout = driver.manage().timeouts().pageLoadTimeout(defaultTimeout);
        System.out.println(pageLoadTimeout.getPageLoadTimeout().toMillis());
        WebDriver.Timeouts scriptTimeout = driver.manage().timeouts().scriptTimeout(defaultTimeout);
        System.out.println(scriptTimeout.getScriptTimeout().toMillis());

        return driver;

    }

    private Map<String, CommandInfo> buildChromiumCommandMappings(String vendorKeyword) {
        String sessionPrefix = "/session/:sessionId/";
        String chromiumPrefix = sessionPrefix + "chromium";
        String vendorPrefix = sessionPrefix + vendorKeyword;

        HashMap<String, CommandInfo> mappings = new HashMap<>();

        mappings.put(ChromiumDriverCommand.LAUNCH_APP,
                new CommandInfo(chromiumPrefix + "/launch_app", HttpMethod.POST));

        String networkConditions = chromiumPrefix + "/network_conditions";
        mappings.put(ChromiumDriverCommand.GET_NETWORK_CONDITIONS,
                new CommandInfo(networkConditions, HttpMethod.GET));
        mappings.put(ChromiumDriverCommand.SET_NETWORK_CONDITIONS,
                new CommandInfo(networkConditions, HttpMethod.POST));
        mappings.put(ChromiumDriverCommand.DELETE_NETWORK_CONDITIONS,
                new CommandInfo(networkConditions, HttpMethod.DELETE));

        mappings.put(ChromiumDriverCommand.EXECUTE_CDP_COMMAND,
                new CommandInfo(vendorPrefix + "/cdp/execute", HttpMethod.POST));

        // Cast / Media Router APIs
        String cast = vendorPrefix + "/cast";
        mappings.put(ChromiumDriverCommand.GET_CAST_SINKS,
                new CommandInfo(cast + "/get_sinks", HttpMethod.GET));
        mappings.put(ChromiumDriverCommand.SET_CAST_SINK_TO_USE,
                new CommandInfo(cast + "/set_sink_to_use", HttpMethod.POST));
        mappings.put(ChromiumDriverCommand.START_CAST_TAB_MIRRORING,
                new CommandInfo(cast + "/start_tab_mirroring", HttpMethod.POST));
        mappings.put(ChromiumDriverCommand.GET_CAST_ISSUE_MESSAGE,
                new CommandInfo(cast + "/get_issue_message", HttpMethod.GET));
        mappings.put(ChromiumDriverCommand.STOP_CASTING,
                new CommandInfo(cast + "/stop_casting", HttpMethod.POST));

        mappings.put(ChromiumDriverCommand.SET_PERMISSION,
                new CommandInfo(sessionPrefix + "/permissions", HttpMethod.POST));

        return unmodifiableMap(mappings);
    }

    static final class ChromiumDriverCommand {
        static final String LAUNCH_APP = "launchApp";
        static final String GET_NETWORK_CONDITIONS = "getNetworkConditions";
        static final String SET_NETWORK_CONDITIONS = "setNetworkConditions";
        static final String DELETE_NETWORK_CONDITIONS = "deleteNetworkConditions";
        static final String EXECUTE_CDP_COMMAND = "executeCdpCommand";
        // Cast Media Router APIs
        static final String GET_CAST_SINKS = "getCastSinks";
        static final String SET_CAST_SINK_TO_USE = "selectCastSink";
        static final String START_CAST_TAB_MIRRORING = "startCastTabMirroring";
        static final String GET_CAST_ISSUE_MESSAGE = "getCastIssueMessage";
        static final String STOP_CASTING = "stopCasting";
        static final String SET_PERMISSION = "setPermission";

        private ChromiumDriverCommand() {
        }
    }

}

// Run the following:

import io.cucumber.testng.AbstractTestNGCucumberTests;
import io.cucumber.testng.CucumberOptions;
import org.testng.annotations.Test;

@CucumberOptions(tags = "",
        features = {"src/test/resources/features/simplelogin.feature"},
        glue = {"cucumber.definition.simplelogin"},
        plugin = { "io.qameta.allure.cucumber7jvm.AllureCucumber7Jvm"})
@Test(groups = {"Login", "Regression"})
public class SimpleLoginStepsRunner extends AbstractTestNGCucumberTests {

}

// With the steps class
import io.cucumber.java.After;
import io.cucumber.java.Before;
import io.cucumber.java.Scenario;
import io.cucumber.java.en.Given;
import io.cucumber.java.en.Then;
import io.cucumber.java.en.When;
import org.openqa.selenium.By;
import org.openqa.selenium.WebElement;
import org.openqa.selenium.remote.RemoteWebDriver;

import java.net.URL;

public class SimpleLoginSteps {
    SetTimeout setTimeout;
    RemoteWebDriver driver;

    @Before
    public void setUp() throws Exception {
        setTimeout = new SetTimeout();
        driver = setTimeout.createDriver(new URL("http://localhost:4444/wd/hub"));
    }

    /**
     * Open my application.
     */
    @Given("I go to the website")
    public void openMyApplication() {
        driver.get(System.getProperty("url"));
    }

    /**
     * Add username.
     */
    @When("I log in using an appropriate user")
    public void addUsername() {
        WebElement usernameTextBox = driver.findElement(By.name("username"));
        usernameTextBox.sendKeys(System.getProperty("username"));

        WebElement passwordTextBox = driver.findElement(By.name("password"));
        passwordTextBox.sendKeys(System.getProperty("password"));

        driver.findElement(By.cssSelector("input[type='submit']")).click();
    }

    /**
     * Open my application.
     */
    @Then("I go to the page {string}")
    public void openMyApplication(String url) {
        long timer = System.currentTimeMillis();
        try {
            driver.get(url);
            System.out.println(driver.getTitle());
        } catch (Exception e) {
            System.out.println("Chrome Driver thread timed out: " + (System.currentTimeMillis() - timer));
            throw e;
        }
    }

    @After
    public void tearDown(Scenario scenario) {
        driver.quit();
        setTimeout.getChromeDriverService().stop();
    }
}

// using the feature file:
Feature: Login

  @login @RegressionTest
  Scenario: Login with valid username and password
    Given I go to the website
    When I log in using an appropriate user
    Then I go to the page "MY LONG RUNNING URL"

Relevant log output

In the tests I get the following logs:
------------------------------------------
Starting ChromeDriver 128.0.6613.84 (606aa55c7d687518d34b55accc5a71ea0bd28727-refs/branch-heads/6613@{#1335}) on port 32549
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
ChromeDriver was started successfully on port 32549.
Aug 27, 2024 7:28:08 PM org.openqa.selenium.remote.tracing.opentelemetry.OpenTelemetryTracer createTracer
INFO: Using OpenTelemetry for tracing
960000
960000
Chrome Driver thread timed out: 580644

Unable to execute request for an existing session: java.net.http.HttpTimeoutException: request timed out
Build info: version: '4.23.1', revision: '656257d8e9'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
Driver info: driver.version: unknown
Build info: version: '4.23.1', revision: '656257d8e9'
System info: os.name: 'Windows 11', os.arch: 'amd64', os.version: '10.0', java.version: '17.0.11'
Driver info: org.openqa.selenium.remote.RemoteWebDriver
Command: [e800b7e2502019a519d0a2750a6e1f0a, get {url=MY LONG RUNNING URL}]
Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 127.0.6533.99, chrome: {chromedriverVersion: 127.0.6533.99 (f31af5097d90..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:40251}, goog:loggingPrefs: {performance: ALL}, networkConnectionEnabled: false, pageLoadStrategy: eager, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://172.26.0.3:4444/sessio..., se:cdpVersion: 127.0.6533.99, se:vnc: ws://172.26.0.3:4444/sessio..., se:vncEnabled: true, se:vncLocalAddress: ws://172.26.0.3:7900, 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}
Session ID: e800b7e2502019a519d0a2750a6e1f0a
org.openqa.selenium.WebDriverException: Unable to execute request for an existing session: java.net.http.HttpTimeoutException: request timed out
Build info: version: '4.23.1', revision: '656257d8e9'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
Driver info: driver.version: unknown
Build info: version: '4.23.1', revision: '656257d8e9'
System info: os.name: 'Windows 11', os.arch: 'amd64', os.version: '10.0', java.version: '17.0.11'
Driver info: org.openqa.selenium.remote.RemoteWebDriver
Command: [e800b7e2502019a519d0a2750a6e1f0a, get {url=MY LONG RUNNING URL}]
Capabilities {acceptInsecureCerts: false, browserName: chrome, browserVersion: 127.0.6533.99, chrome: {chromedriverVersion: 127.0.6533.99 (f31af5097d90..., userDataDir: /tmp/.org.chromium.Chromium...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:40251}, goog:loggingPrefs: {performance: ALL}, networkConnectionEnabled: false, pageLoadStrategy: eager, platformName: linux, proxy: Proxy(), se:bidiEnabled: false, se:cdp: ws://172.26.0.3:4444/sessio..., se:cdpVersion: 127.0.6533.99, se:vnc: ws://172.26.0.3:4444/sessio..., se:vncEnabled: true, se:vncLocalAddress: ws://172.26.0.3:7900, 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}
Session ID: e800b7e2502019a519d0a2750a6e1f0a
	at java.base@17.0.11/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base@17.0.11/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base@17.0.11/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base@17.0.11/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base@17.0.11/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
	at app//org.openqa.selenium.remote.ErrorCodec.decode(ErrorCodec.java:167)
	at app//org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:138)
	at app//org.openqa.selenium.remote.codec.w3c.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:50)
	at app//org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:190)
	at app//org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:545)
	at app//org.openqa.selenium.remote.RemoteWebDriver.get(RemoteWebDriver.java:313)
	at app//cucumber.definition.simplelogin.SimpleLoginSteps.openMyApplication(SimpleLoginSteps.java:55)

-------------------------------------------
and in the docker chrome container I get
-------------------------------------------
2024-08-27T17:33:17.583271379Z 17:33:17.581 WARN [SpanWrappedHttpHandler.execute] - Unable to execute request: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.583362830Z Build info: version: '4.23.1', revision: '656257d8e9'
2024-08-27T17:33:17.583365926Z System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
2024-08-27T17:33:17.583367843Z Driver info: driver.version: unknown
2024-08-27T17:33:17.583369746Z org.openqa.selenium.TimeoutException: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.583389755Z Build info: version: '4.23.1', revision: '656257d8e9'
2024-08-27T17:33:17.583391534Z System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
2024-08-27T17:33:17.583393274Z Driver info: driver.version: unknown
2024-08-27T17:33:17.583394835Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:408)
2024-08-27T17:33:17.583397103Z 	at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
2024-08-27T17:33:17.583398796Z 	at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)
2024-08-27T17:33:17.583400462Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:374)
2024-08-27T17:33:17.583402168Z 	at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:54)
2024-08-27T17:33:17.583403871Z 	at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)
2024-08-27T17:33:17.583405504Z 	at org.openqa.selenium.grid.node.DefaultActiveSession.execute(DefaultActiveSession.java:62)
2024-08-27T17:33:17.583407184Z 	at org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:126)
2024-08-27T17:33:17.583408941Z 	at org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:633)
2024-08-27T17:33:17.583410627Z 	at org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)
2024-08-27T17:33:17.583412273Z 	at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:397)
2024-08-27T17:33:17.583413882Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.583415568Z 	at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:87)
2024-08-27T17:33:17.583417329Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.583418972Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-27T17:33:17.583420658Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.583423838Z 	at org.openqa.selenium.grid.node.Node.execute(Node.java:270)
2024-08-27T17:33:17.583425794Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-27T17:33:17.583428975Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.583430656Z 	at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
2024-08-27T17:33:17.583432424Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-27T17:33:17.583433980Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.583435612Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-27T17:33:17.583437317Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.583441737Z 	at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
2024-08-27T17:33:17.583443440Z 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
2024-08-27T17:33:17.583445036Z 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2024-08-27T17:33:17.583446583Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2024-08-27T17:33:17.583448186Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2024-08-27T17:33:17.583449924Z 	at java.base/java.lang.Thread.run(Thread.java:840)
2024-08-27T17:33:17.583451625Z Caused by: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.583453267Z 	at java.net.http/jdk.internal.net.http.ResponseTimerEvent.handle(ResponseTimerEvent.java:63)
2024-08-27T17:33:17.583454896Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1270)
2024-08-27T17:33:17.583456546Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:899)
2024-08-27T17:33:17.587865063Z 17:33:17.586 WARN [SeleniumSpanExporter$1.lambda$export$1] - org.openqa.selenium.TimeoutException: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.587929517Z Build info: version: '4.23.1', revision: '656257d8e9'
2024-08-27T17:33:17.587933065Z System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
2024-08-27T17:33:17.587935151Z Driver info: driver.version: unknown
2024-08-27T17:33:17.587936944Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:408)
2024-08-27T17:33:17.587939829Z 	at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
2024-08-27T17:33:17.587941573Z 	at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)
2024-08-27T17:33:17.587943219Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:374)
2024-08-27T17:33:17.587944860Z 	at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:54)
2024-08-27T17:33:17.587946657Z 	at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)
2024-08-27T17:33:17.587948532Z 	at org.openqa.selenium.grid.node.DefaultActiveSession.execute(DefaultActiveSession.java:62)
2024-08-27T17:33:17.587950758Z 	at org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:126)
2024-08-27T17:33:17.587953095Z 	at org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:633)
2024-08-27T17:33:17.587955327Z 	at org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)
2024-08-27T17:33:17.587957096Z 	at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:397)
2024-08-27T17:33:17.587975412Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.587977400Z 	at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:87)
2024-08-27T17:33:17.587979220Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.587980922Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-27T17:33:17.587983219Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.587984920Z 	at org.openqa.selenium.grid.node.Node.execute(Node.java:270)
2024-08-27T17:33:17.587986495Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-27T17:33:17.587988217Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-27T17:33:17.587990033Z 	at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
2024-08-27T17:33:17.587993506Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-27T17:33:17.587995776Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.587997885Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-27T17:33:17.587999839Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-27T17:33:17.588001537Z 	at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
2024-08-27T17:33:17.588004141Z 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
2024-08-27T17:33:17.588005894Z 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2024-08-27T17:33:17.588008061Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2024-08-27T17:33:17.588009845Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2024-08-27T17:33:17.588011806Z 	at java.base/java.lang.Thread.run(Thread.java:840)
2024-08-27T17:33:17.588014298Z Caused by: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.588015992Z 	at java.net.http/jdk.internal.net.http.ResponseTimerEvent.handle(ResponseTimerEvent.java:63)
2024-08-27T17:33:17.588017753Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1270)
2024-08-27T17:33:17.588019445Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:899)
2024-08-27T17:33:17.588021489Z 
2024-08-27T17:33:17.588023095Z 17:33:17.587 WARN [SeleniumSpanExporter$1.lambda$export$1] - Unable to execute request: java.net.http.HttpTimeoutException: request timed out
2024-08-27T17:33:17.588024939Z Build info: version: '4.23.1', revision: '656257d8e9'
2024-08-27T17:33:17.588026637Z System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
2024-08-27T17:33:17.588060549Z Driver info: driver.version: unknown
2024-08-27T17:33:17.590522344Z 17:33:17.589 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "5a030d9fbc546faaf7d48716350dfdc0","eventTime": 1724779990762414291,"eventName": "exception","attributes": {"exception.message": "Unable to execute request: java.net.http.HttpTimeoutException: request timed out\nBuild info: version: '4.23.1', revision: '656257d8e9'\nSystem info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'\nDriver info: driver.version: unknown","exception.stacktrace": "org.openqa.selenium.TimeoutException: java.net.http.HttpTimeoutException: request timed out\nBuild info: version: '4.23.1', revision: '656257d8e9'\nSystem info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'\nDriver info: driver.version: unknown\n\tat org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:408)\n\tat org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)\n\tat org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)\n\tat org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:374)\n\tat org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:54)\n\tat org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)\n\tat org.openqa.selenium.grid.node.DefaultActiveSession.execute(DefaultActiveSession.java:62)\n\tat org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:126)\n\tat org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:633)\n\tat org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)\n\tat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:397)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:69)\n\tat org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:87)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:69)\n\tat org.openqa.selenium.grid.node.Node.execute(Node.java:270)\n\tat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)\n\tat org.openqa.selenium.remote.http.Route.execute(Route.java:69)\n\tat org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)\n\tat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)\n\tat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)\n\tat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)\n\tat org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)\n\tat java.base\u002fjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)\n\tat java.base\u002fjava.util.concurrent.FutureTask.run(FutureTask.java:264)\n\tat java.base\u002fjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)\n\tat java.base\u002fjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)\n\tat java.base\u002fjava.lang.Thread.run(Thread.java:840)\nCaused by: java.net.http.HttpTimeoutException: request timed out\n\tat java.net.http\u002fjdk.internal.net.http.ResponseTimerEvent.handle(ResponseTimerEvent.java:63)\n\tat java.net.http\u002fjdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1270)\n\tat java.net.http\u002fjdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:899)\n","exception.type": "org.openqa.selenium.TimeoutException","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "172.26.0.3:5555","http.method": "POST","http.request_content_length": "105","http.scheme": "HTTP","http.target": "\u002fsession\u002fe800b7e2502019a519d0a2750a6e1f0a\u002furl","http.user_agent": "selenium\u002f4.23.1 (java windows)"}}

Operating System

Windows 11 and Docker

Selenium version

Java 4.23.1

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

Chrome Remote

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

Chrome Browser version 127.0.6533.99

Are you using Selenium Grid?

Grid version: 4.23.1
@github-actions GitHub Actions
Copy link

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

@codex70
Copy link
Author

codex70 commented Aug 28, 2024

image

Here you can clearly see the test failing after exactly 9 minutes, followed by a further 9 minutes to quit and stop the driver in the tear down procedure.

@diemol
Copy link
Member

diemol commented Aug 28, 2024

Why are you not setting any timeout on the Grid?

@codex70
Copy link
Author

codex70 commented Aug 28, 2024

Why are you not setting any timeout on the Grid?

Because I wasn't aware that was an option, I must have missed that. Will try that now

@github-actions github-actions bot deleted a comment Aug 28, 2024
@codex70
Copy link
Author

codex70 commented Aug 28, 2024 •
edited
Loading

OK, I've tried with the following options in the docker compose file, but it hasn't made any difference:

  selenium-hub:
    image: selenium/hub:latest
    container_name: selenium-hub
    ports:
      - "4442:4442"
      - "4443:4443"
      - "4444:4444"
    environment:
      - GRID_TIMEOUT=960000
      - GRID_BROWSER_TIMEOUT=960000
      - SE_NODE_SESSION_TIMEOUT=960000

Are there any other settings for the chrome node container, or anything else that I might be missing?

@diemol
Copy link
Member

diemol commented Aug 28, 2024

GRID_TIMEOUT and GRID_BROWSER_TIMEOUT don't exist. Have you checked the docs at https://github.com/SeleniumHQ/docker-selenium?

@codex70
Copy link
Author

codex70 commented Aug 28, 2024

Thank you, the example I found must have been out of date.

I have now put:

    environment:
      - SE_NODE_SESSION_TIMEOUT=960000
      - SE_SESSION_REQUEST_TIMEOUT=960000

However this still makes no difference. One thing I did notice was that in the error message I get the following details from the driver, which do not appear to relate to any of the timeouts I have set:

timeouts: {implicit: 0, pageLoad: 300000, script: 30000}

Are there any other settings that I'm missing or have misunderstood?

@codex70
Copy link
Author

codex70 commented Aug 28, 2024

If I set the following options, they get passed through to selenium, but it still makes no difference:

        options.setImplicitWaitTimeout(clientTimeout);
        options.setPageLoadTimeout(defaultTimeout);
        options.setScriptTimeout(defaultTimeout);

Whatever settings I change, I still end up with the following errors in the selenium hub docker container:

15:57:10.157 WARN [SeleniumSpanExporter$1.lambda$export$1] - org.openqa.selenium.TimeoutException: java.net.http.HttpTimeoutException: request timed out
2024-08-28T15:57:10.158592962Z Build info: version: '4.23.1', revision: '656257d8e9'
2024-08-28T15:57:10.158596225Z System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.15.153.1-microsoft-standard-WSL2', java.version: '17.0.12'
2024-08-28T15:57:10.158598760Z Driver info: driver.version: unknown
2024-08-28T15:57:10.158601055Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute0(JdkHttpClient.java:408)
2024-08-28T15:57:10.158604184Z 	at org.openqa.selenium.remote.http.RetryRequest.lambda$apply$5(RetryRequest.java:81)
2024-08-28T15:57:10.158606401Z 	at dev.failsafe.Functions.lambda$toCtxSupplier$11(Functions.java:243)
2024-08-28T15:57:10.158608620Z 	at dev.failsafe.Functions.lambda$get$0(Functions.java:46)
2024-08-28T15:57:10.158610964Z 	at dev.failsafe.internal.RetryPolicyExecutor.lambda$apply$0(RetryPolicyExecutor.java:74)
2024-08-28T15:57:10.158613151Z 	at dev.failsafe.internal.RetryPolicyExecutor.lambda$apply$0(RetryPolicyExecutor.java:74)
2024-08-28T15:57:10.158626748Z 	at dev.failsafe.internal.FallbackExecutor.lambda$apply$0(FallbackExecutor.java:51)
2024-08-28T15:57:10.158629231Z 	at dev.failsafe.SyncExecutionImpl.executeSync(SyncExecutionImpl.java:187)
2024-08-28T15:57:10.158631440Z 	at dev.failsafe.FailsafeExecutor.call(FailsafeExecutor.java:376)
2024-08-28T15:57:10.158633684Z 	at dev.failsafe.FailsafeExecutor.get(FailsafeExecutor.java:112)
2024-08-28T15:57:10.158635936Z 	at org.openqa.selenium.remote.http.RetryRequest.lambda$apply$6(RetryRequest.java:81)
2024-08-28T15:57:10.158638225Z 	at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
2024-08-28T15:57:10.158640589Z 	at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:55)
2024-08-28T15:57:10.158642755Z 	at org.openqa.selenium.remote.http.jdk.JdkHttpClient.execute(JdkHttpClient.java:374)
2024-08-28T15:57:10.158644917Z 	at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:54)
2024-08-28T15:57:10.158647114Z 	at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:90)
2024-08-28T15:57:10.158649283Z 	at org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:181)
2024-08-28T15:57:10.158651434Z 	at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:397)
2024-08-28T15:57:10.158653615Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-28T15:57:10.158655807Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-28T15:57:10.158658082Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-28T15:57:10.158661594Z 	at org.openqa.selenium.grid.router.Router.execute(Router.java:87)
2024-08-28T15:57:10.158663839Z 	at org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)
2024-08-28T15:57:10.158666106Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-28T15:57:10.158668245Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-28T15:57:10.158670517Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-28T15:57:10.158672718Z 	at org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)
2024-08-28T15:57:10.158674909Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-28T15:57:10.158677168Z 	at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:360)
2024-08-28T15:57:10.158679502Z 	at org.openqa.selenium.remote.http.Route.execute(Route.java:69)
2024-08-28T15:57:10.158681929Z 	at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
2024-08-28T15:57:10.158684357Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-28T15:57:10.158686538Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-28T15:57:10.158691631Z 	at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2024-08-28T15:57:10.158693866Z 	at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:63)
2024-08-28T15:57:10.158695974Z 	at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
2024-08-28T15:57:10.158700042Z 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
2024-08-28T15:57:10.158702628Z 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2024-08-28T15:57:10.158704794Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2024-08-28T15:57:10.158706967Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2024-08-28T15:57:10.158709164Z 	at java.base/java.lang.Thread.run(Thread.java:840)
2024-08-28T15:57:10.158711293Z Caused by: java.net.http.HttpTimeoutException: request timed out
2024-08-28T15:57:10.158713455Z 	at java.net.http/jdk.internal.net.http.ResponseTimerEvent.handle(ResponseTimerEvent.java:63)
2024-08-28T15:57:10.158715696Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1270)
2024-08-28T15:57:10.158717958Z 	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:899)

It still consistently fails at 9 minutes, then takes a further 9 minutes to close and stop the driver.

@codex70
Copy link
Author

codex70 commented Aug 29, 2024

As a follow up, if I run with standalone chrome instead of going through selenium hub, the above code works as expected and there are no timeouts. It doesn't really solve the problem, but for me, for the time being, this is a work around I can live with.

@diemol, thank you for all your help, I'm not sure if you want me to close this issue, or leave it open?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
I-defect needs-triaging
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@codex70 @diemol and others