[jira] [Updated] (HTTPCLIENT-2386) httpClient5 socketTimeoutException in dataChannel with connectTimeout value
[
https://issues.apache.org/jira/browse/HTTPCLIENT-2386?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Cenk Pekyaman updated HTTPCLIENT-2386:
--
Description:
We are using http-client-5 under our api-client layer with async + TLS. Once in
a while, we get a timeout exception like this:
"{*}java.net.SocketTimeoutException: 2 SECONDS{*}" in some requests. and from
the stack trace, we see that the exception is coming from
"InternalDataChannel.onTimeout". but the value we see is actually the
{*}connectTimeout{*}, not the readTimeout({*}socketTimeout{*}) we set for the
request.
we specify our *connectTimeout* as *2 seconds* in
*PoolingAsyncClientConnectionManagerBuilder* during client creation. we specify
our *socketTimeout* as *10 seconds* in *RequestConfig* of *HttpClientContext*
during request execution.
this is how we make the call (a bit simplified):
{{// the last parameter is our class implementing FutureCallback}}
{{Future> clientFuture =
asyncHttpClient.execute(asyncRequestProducer, responseConsumer, null,
httpClientContext, this);}}
{{// callTimeout is essentially connectTimeout + socketTimeout by default.}}
{{return clientFuture.get(callTimeout, TimeUnit.MILLISECONDS);}}
We suspect that the client completes the initial connect step with
"InternalConnectChannel" and then the socket is handed over to
"InternalDataChannel" to do the TLS handshake in "{*}startTls{*}", which either
takes too long to complete, or hangs. Since we don't specify handshakeTimeout
in our tlsconfig, *DefaultAsyncClientConnectionOperator* seems to be using
*connectTimeout* for this stage (in the callback called after connection is
established ?).
Code flow is essentially correct but getting a generic socketTimeoutException
with the value of connectTimeout seems a bit confusing, as we normally expect
some ConnectTimeoutException if we really have a connection timeout, or the
other way around.
This is an example stack trace for such a case:
{{ at org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$2.failed(InternalAbstractHttpAsyncClient.java:364)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncRedirectExec$1.failed(AsyncRedirectExec.java:246)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncConnectExec$2.failed(AsyncConnectExec.java:233)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$4.failed(PoolingAsyncClientConnectionManager.java:482)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.FutureContribution.failed(FutureContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.exception(SSLIOSession.java:233)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.timeout(SSLIOSession.java:223)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:170)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:239)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:128)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:92)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
[httpcore5-5.3.4.jar:5.3.4] at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.net.SocketTimeoutException: 2 SECONDS at
org.apache.hc.core5.io.SocketTimeoutExceptionFactory
[jira] [Updated] (HTTPCLIENT-2386) httpClient5 socketTimeoutException in dataChannel with connectTimeout value
[
https://issues.apache.org/jira/browse/HTTPCLIENT-2386?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Cenk Pekyaman updated HTTPCLIENT-2386:
--
Description:
We are using http-client-5 under our api-client layer with async + TLS. Once in
a while, we get a timeout exception like this:
"{*}java.net.SocketTimeoutException: 2 SECONDS{*}" in some requests. and from
the stack trace, we see that the exception is coming from
"InternalDataChannel.onTimeout". but the value we see is actually the
{*}connectTimeout{*}, not the readTimeout({*}socketTimeout{*}) we set for the
request.
we specify our *connectTimeout* as *2 seconds* in
*PoolingAsyncClientConnectionManagerBuilder* during client creation. we specify
our *socketTimeout* as *10 seconds* in *RequestConfig* of *HttpClientContext*
during request execution.
this is how we make the call (a bit simplified):
{{// the last parameter is our class implementing FutureCallback}}
Future> clientFuture =
asyncHttpClient.execute(asyncRequestProducer, responseConsumer, null,
httpClientContext, this);
{{// callTimeout is essentially connectTimeout + socketTimeout by default.}}
return clientFuture.get(callTimeout, TimeUnit.MILLISECONDS);
We suspect that the client completes the initial connect step with
"InternalConnectChannel" and then the socket is handed over to
"InternalDataChannel" to do the TLS handshake in "{*}startTls{*}", which either
takes too long to complete, or hangs.
Since we don't specify handshakeTimeout in our tlsconfig,
*DefaultAsyncClientConnectionOperator* seems to be using *connectTimeout* for
this stage (in the callback called after connection is established ?).
Code flow is essentially correct but getting a generic socketTimeoutException
with the value of connectTimeout seems a bit confusing, as we normally expect
some ConnectTimeoutException if we really have a connection timeout, or the
other way around.
This is an example stack trace for such a case:
{{ at org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$2.failed(InternalAbstractHttpAsyncClient.java:364)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncRedirectExec$1.failed(AsyncRedirectExec.java:246)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncConnectExec$2.failed(AsyncConnectExec.java:233)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$4.failed(PoolingAsyncClientConnectionManager.java:482)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.FutureContribution.failed(FutureContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.exception(SSLIOSession.java:233)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.timeout(SSLIOSession.java:223)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:170)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:239)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:128)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:92)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
[httpcore5-5.3.4.jar:5.3.4] at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.net.SocketTimeoutException: 2 SECONDS at
org.apache.hc.core5.io.SocketTimeoutExceptionF
[jira] [Updated] (HTTPCLIENT-2386) httpClient5 socketTimeoutException in dataChannel with connectTimeout value
[
https://issues.apache.org/jira/browse/HTTPCLIENT-2386?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Cenk Pekyaman updated HTTPCLIENT-2386:
--
Description:
We are using http-client-5 under our api-client layer with async + TLS. Once in
a while, we get a timeout exception like this:
"{*}java.net.SocketTimeoutException: 2 SECONDS{*}" in some requests. and from
the stack trace, we see that the exception is coming from
"InternalDataChannel.onTimeout". but the value we see is actually the
{*}connectTimeout{*}, not the readTimeout({*}socketTimeout{*}) we set for the
request.
we specify our *connectTimeout* as *2 seconds* in
*PoolingAsyncClientConnectionManagerBuilder* during client creation. we specify
our *socketTimeout* as *10 seconds* in *RequestConfig* of *HttpClientContext*
during request execution.
this is how we make the call (a bit simplified):
{{// the last parameter is our class implementing FutureCallback}}
{{Future> clientFuture =
asyncHttpClient.execute(asyncRequestProducer, responseConsumer, null,
httpClientContext, this);}}
{{// callTimeout is essentially connectTimeout + socketTimeout by default.}}
{{return clientFuture.get(callTimeout, TimeUnit.MILLISECONDS);}}
We suspect that the client completes the initial connect step with
"InternalConnectChannel" and then the socket is handed over to
"InternalDataChannel" to do the TLS handshake in "{*}startTls{*}", which either
takes too long to complete, or hangs.
Since we don't specify handshakeTimeout in our tlsconfig,
*DefaultAsyncClientConnectionOperator* seems to be using *connectTimeout* for
this stage (in the callback called after connection is established ?).
Code flow is essentially correct but getting a generic socketTimeoutException
with the value of connectTimeout seems a bit confusing, as we normally expect
some ConnectTimeoutException if we really have a connection timeout, or the
other way around.
This is an example stack trace for such a case:
{{ at org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$2.failed(InternalAbstractHttpAsyncClient.java:364)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncRedirectExec$1.failed(AsyncRedirectExec.java:246)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncConnectExec$2.failed(AsyncConnectExec.java:233)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$4.failed(PoolingAsyncClientConnectionManager.java:482)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.FutureContribution.failed(FutureContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.exception(SSLIOSession.java:233)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.timeout(SSLIOSession.java:223)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:170)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:239)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:128)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:92)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
[httpcore5-5.3.4.jar:5.3.4] at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.net.SocketTimeoutException: 2 SECONDS at
org.apache.hc.core5.io.SocketTimeoutExceptionFactory.c
[jira] [Updated] (HTTPCLIENT-2386) httpClient5 socketTimeoutException in dataChannel with connectTimeout value
[
https://issues.apache.org/jira/browse/HTTPCLIENT-2386?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Cenk Pekyaman updated HTTPCLIENT-2386:
--
Description:
We are using http-client-5 under our api-client layer with async + TLS. Once in
a while, we get a timeout exception like this:
"{*}java.net.SocketTimeoutException: 2 SECONDS{*}" in some requests. and from
the stack trace, we see that the exception is coming from
"InternalDataChannel.onTimeout". but the value we see is actually the
{*}connectTimeout{*}, not the readTimeout({*}socketTimeout{*}) we set for the
request.
we specify our *connectTimeout* as *2 seconds* in
*PoolingAsyncClientConnectionManagerBuilder* during client creation. we specify
our *socketTimeout* as *10 seconds* in *RequestConfig* of *HttpClientContext*
during request execution.
this is how we make the call (a bit simplified):
{{// the last parameter is our class implementing FutureCallback }}
{{Future> clientFuture =
asyncHttpClient.execute(asyncRequestProducer, responseConsumer, null,
httpClientContext, this);}}
{{// callTimeout is essentially connectTimeout + socketTimeout by default. }}
{{return clientFuture.get(callTimeout, TimeUnit.MILLISECONDS);}}
We suspect that the client completes the initial connect step with
"InternalConnectChannel" and then the socket is handed over to
"InternalDataChannel" to do the TLS handshake in "{*}startTls{*}", which either
takes too long to complete, or hangs.
Since we don't specify handshakeTimeout in our tlsconfig,
*DefaultAsyncClientConnectionOperator* seems to be using *connectTimeout* for
this stage (in the callback called after connection is established ?).
Code flow is essentially correct but getting a generic socketTimeoutException
with the value of connectTimeout seems a bit confusing, as we normally expect
some ConnectTimeoutException if we really have a connection timeout, or the
other way around.
This is an example stack trace for such a case:
{{ at org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$2.failed(InternalAbstractHttpAsyncClient.java:364)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncRedirectExec$1.failed(AsyncRedirectExec.java:246)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.client5.http.impl.async.AsyncConnectExec$2.failed(AsyncConnectExec.java:233)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$4.failed(PoolingAsyncClientConnectionManager.java:482)
[httpclient5-5.4.4.jar:5.4.4] at
org.apache.hc.core5.concurrent.BasicFuture.failed(BasicFuture.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.ComplexFuture.failed(ComplexFuture.java:79)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.FutureContribution.failed(FutureContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.concurrent.CallbackContribution.failed(CallbackContribution.java:52)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.exception(SSLIOSession.java:233)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.ssl.SSLIOSession$1.timeout(SSLIOSession.java:223)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:170)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:239)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:166)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:128)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:92)
[httpcore5-5.3.4.jar:5.3.4] at
org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
[httpcore5-5.3.4.jar:5.3.4] at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.net.SocketTimeoutException: 2 SECONDS at
org.apache.hc.core5.io.SocketTimeoutExceptionFactory
