JDK-8294958 : java/net/httpclient/ConnectTimeout tests are slow
  • Type: Enhancement
  • Component: core-libs
  • Sub-Component: java.net
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2022-10-07
  • Updated: 2023-01-03
  • Resolved: 2022-10-11
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 17 JDK 20
17.0.7-oracleFixed 20 b19Fixed
Related Reports
Relates :  
Description
There are 6 ConnectTimeout tests with total runtime close to 7 minutes. Most of the time they are just waiting for a timeout to expire, and they only verify the type of exception thrown.

We can reduce the number of iterations and use shorter timeouts, and still get the expected behavior.
Comments
Hi [~dfuchs] > I increased the mentioned timeout in AbstractConnectTimeoutHandshake to 500 ms and will observe how this influences our tests. That did not fix the test failures. > If it does not help I will revert this change and update this issue Reverting 8294958 fixed the mentioned test failures. Regarding the other suggestion: >or (preferably) fix the firewall to stop sending SYN cookies for outgoing traffic. I try to find someone who is willing to adjust this and so far it is unclear what will be the outcome of it.
18-10-2022

Hi [~mbaesken] this looks like the reduced timeout tripped a SYN flood protection on some firewall. The tests are connecting to example.com:81, and expecting that example.com will ignore the connection attempt. Your log indicates that the connection was accepted and then reset. I've seen similar behavior when there was a Checkpoint firewall with misconfigured "Accelerated SYN defender" [1] that identified the connection attempts as SYN flood and started sending SYN+ACK packets. I'm assuming that this is your internal firewall - otherwise our CI would experience the same problems. As for a solution, there are 2 options: either revert the timeouts to their original values, or (preferably) fix the firewall to stop sending SYN cookies for outgoing traffic. [1] https://sc1.checkpoint.com/documents/R81/WebAdminGuides/EN/CP_R81_PerformanceTuning_AdminGuide/Topics-PTG/SecureXL-Accelerated-SYN-Defender.htm
14-10-2022

Thank you!
14-10-2022

Hi [~dfuchs] , I increased the mentioned timeout in AbstractConnectTimeoutHandshake to 500 ms and will observe how this influences our tests. If it does not help I will revert this change and update this issue (and maybe create a new JBS issue).
14-10-2022

Hi [~mbaesken] - do the failures disappear if you revert this change? We haven't experienced any direct failures of these tests in our CI, though we have seen a couple of other tests failing intermittently (but rarely) due to lack of available ephemeral ports. It may be that making tests faster means that ephemeral ports will be exhausted faster - but this usually doesn't result in connection reset - (rather, in a bind exception or in a connect exception - e.g: Caused by: java.net.BindException: Address already in use: connect).
14-10-2022

IIRC this change removed some test cases but didn't change anything else in the tests otherwise. Hmmm... except maybe in AbstractConnectTimeoutHandshake https://github.com/openjdk/jdk/commit/fe70487d0bc53149150c23d39287d9856c5a0e95#diff-4857987febe7cfbb9dff13e4aa567ca858e2c9c41e7a1ffb77b8ae3e156d46f9 Maybe we should be using 500ms there rather than 100ms (which is a new value for that test)...
14-10-2022

We are getting now a lot of errors on Linux and Windows in tests like those: java/net/httpclient/ConnectTimeoutNoProxyAsync.java java/net/httpclient/ConnectTimeoutNoProxySync.java java/net/httpclient/ConnectTimeoutWithProxyAsync.java java/net/httpclient/ConnectTimeoutWithProxySync.java since 11th October - could this be related ? example exception : timeoutAsync(requestVersion=HTTP_1_1, scheme=http, method=GET, connectTimeout=PT0.1S, requestTimeout=null, proxy=java.net.ProxySelector$StaticProxySelector@61cce79d) iteration 0 Client: received in 132 millis Caught expected HttpConnectTimeoutException with ConnectException cause: java.net.http.HttpConnectTimeoutException: HTTP connect timed out java.net.ConnectException: HTTP connect timed out iteration 1 Client: received in 8217 millis java.io.IOException: HTTP/1.1 header parser received no bytes at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Utils.java:348) at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.onReadError(Http1Response.java:574) at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Http1AsyncReceiver.java:302) at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:268) at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1591) Caused by: java.net.SocketException: Connection reset at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:401) at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:434) at java.net.http/jdk.internal.net.http.SocketTube.readAvailable(SocketTube.java:1178) at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:841) at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181) at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:782) at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:965) at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:253) at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:1346) at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:1291) at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1291) test ConnectTimeoutNoProxyAsync.timeoutNoProxyAsync(HTTP_1_1, "http", "GET", PT0.1S, null): failure java.lang.AssertionError: Expected HttpConnectTimeoutException, got:java.io.IOException: HTTP/1.1 header parser received no bytes at org.testng.Assert.fail(Assert.java:99) at AbstractConnectTimeout.assertExceptionTypeAndCause(AbstractConnectTimeout.java:238) at AbstractConnectTimeout.timeoutAsync(AbstractConnectTimeout.java:197) at AbstractConnectTimeout.timeoutNoProxyAsync(AbstractConnectTimeout.java:157) at ConnectTimeoutNoProxyAsync.timeoutNoProxyAsync(ConnectTimeoutNoProxyAsync.java:45) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) at java.base/java.lang.reflect.Method.invoke(Method.java:578) at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) at org.testng.TestRunner.privateRun(TestRunner.java:764) at org.testng.TestRunner.run(TestRunner.java:585) at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) at org.testng.SuiteRunner.run(SuiteRunner.java:286) at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) at org.testng.TestNG.runSuites(TestNG.java:1069) at org.testng.TestNG.run(TestNG.java:1037) at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:93) at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:53) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) at java.base/java.lang.reflect.Method.invoke(Method.java:578) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:125) at java.base/java.lang.Thread.run(Thread.java:1591)
14-10-2022

Changeset: fe70487d Author: Daniel JeliƄski <djelinski@openjdk.org> Date: 2022-10-11 08:50:01 +0000 URL: https://git.openjdk.org/jdk/commit/fe70487d0bc53149150c23d39287d9856c5a0e95
11-10-2022

A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/10605 Date: 2022-10-07 11:53:25 +0000
07-10-2022