[
https://issues.apache.org/jira/browse/HTTPCLIENT-2135?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17415184#comment-17415184
]
Ryan Schmitt commented on HTTPCLIENT-2135:
------------------------------------------
I captured some logging statements to see what changed. Before:
{code}
14 Sep 2021 14:19:49,018 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.IOSessionImpl: c-0000000000[ACTIVE][rc:c] protocol
upgrade class org.apache.hc.core5.http2.impl.nio.ClientHttpProtocolNegotiator
14 Sep 2021 14:19:49,018 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester:
https://localhost:8444 connected c-0000000000
/127.0.0.1:57095->localhost/127.0.0.1:8444
14 Sep 2021 14:19:49,020 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection:
c-0000000000 start TLS
14 Sep 2021 14:19:49,029 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.ssl.AbstractClientTlsStrategy: Enabled protocols:
[TLSv1, TLSv1.1, TLSv1.2]
14 Sep 2021 14:19:49,029 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.ssl.AbstractClientTlsStrategy: Enabled cipher
suites: [...]
14 Sep 2021 14:19:49,054 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager:
ep-0000000000 connected c-0000000000
14 Sep 2021 14:19:49,054 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-0000000000
endpoint connected
14 Sep 2021 14:19:49,054 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-0000000001 connected
to target
14 Sep 2021 14:19:49,054 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-0000000001 route
fully established
14 Sep 2021 14:19:49,055 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec: ex-0000000001
executing GET /fuzz?size=1048576&duration=0&offset=0&chunked=false HTTP/1.1
14 Sep 2021 14:19:49,057 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-0000000000
start execution ex-0000000001
14 Sep 2021 14:19:49,057 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager:
ep-0000000000 executing exchange ex-0000000001 over c-0000000000
14 Sep 2021 14:19:49,058 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection:
c-0000000000 RequestExecutionCommand with NORMAL priority
14 Sep 2021 14:19:49,058 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[ACTIVE][rw:c][ACTIVE][rw][NEED_UNWRAP][0][0][296] Enqueued
RequestExecutionCommand with priority IMMEDIATE
14 Sep 2021 14:19:49,058 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[ACTIVE][rw:c][ACTIVE][rw][NEED_UNWRAP][0][0][296] Event cleared [c]
14 Sep 2021 14:19:52,069 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[ACTIVE][r:c][ACTIVE][rw][NEED_UNWRAP][0][0][0] Close IMMEDIATE
14 Sep 2021 14:19:52,070 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec: ex-0000000001
execution failed: 2500 MILLISECONDS
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient:
ex-0000000001 request failed: 2500 MILLISECONDS
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager:
ep-0000000000 close IMMEDIATE
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection:
c-0000000000 Shutdown connection IMMEDIATE
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[CLOSED][][CLOSED][rw][NEED_UNWRAP][0][0][0] Close IMMEDIATE
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-0000000000
endpoint closed
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-0000000000
discarding endpoint
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager:
ep-0000000000 releasing endpoint
14 Sep 2021 14:19:52,071 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager:
ep-0000000000 connection released [route: {s}->https://localhost:8444][total
available: 0; route allocated: 0 of 2147483647; total allocated: 0 of
2147483647]
{code}
After:
{code}
14 Sep 2021 14:18:21,099 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.IOSessionImpl: c-0000000000[ACTIVE][rc:c] protocol
upgrade class org.apache.hc.core5.http2.impl.nio.ClientHttpProtocolNegotiator
14 Sep 2021 14:18:21,100 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester:
https://localhost:8444 connected c-0000000000
/127.0.0.1:56990->localhost/127.0.0.1:8444
14 Sep 2021 14:18:21,104 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection:
c-0000000000 start TLS
14 Sep 2021 14:18:21,113 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.ssl.AbstractClientTlsStrategy: Enabled protocols:
[TLSv1, TLSv1.1, TLSv1.2]
14 Sep 2021 14:18:21,113 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.client5.http.ssl.AbstractClientTlsStrategy: Enabled cipher
suites:[...]
14 Sep 2021 14:18:21,140 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[ACTIVE][rw:c][ACTIVE][r][NEED_UNWRAP][0][0][296] Event cleared [c]
14 Sep 2021 14:18:24,153 [DEBUG] (httpclient-dispatch-1)
org.apache.hc.core5.reactor.ssl.SSLIOSession:
c-0000000000[ACTIVE][r:c][ACTIVE][r][NEED_UNWRAP][0][0][0] Close IMMEDIATE
{code}
So the handshake is still timing out, but the exception isn't being reported.
I'm also not seeing the "route fully established" messages associated with
successful TCP/IP connection establishment.
> TLS handshake timeouts cannot be controlled through RequestConfig
> -----------------------------------------------------------------
>
> Key: HTTPCLIENT-2135
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2135
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic)
> Affects Versions: 5.0.3
> Reporter: Ryan Schmitt
> Priority: Major
> Fix For: 5.2-alpha1
>
>
> Apparently as a consequence of HTTPCLIENT-2091 and/or HTTPCLIENT-2099, TLS
> handshake timeouts can no longer be specified through any of the three
> {{RequestConfig}} timeout parameters (connect, connection request, response).
> The only way to limit TLS handshake duration is through low-level socket
> configuration (socket timeout), which of course affects more than just TLS
> handshakes.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
