Hello,
�
We are having an issue with HttpClient 5 beta4 / HttpCore 5 Beta7 and socket
timeout after switching from asyncClient 1.3.
�
Our requests have a response timeout of 4 seconds. When a response timeout
occurs we see this in our log:
2019-05-27 13:05:35 � � � � [62.73.191.161] GetAccomodationAvail � � � �
Response timeout � � � � � � � java.net.SocketTimeoutException: 4,000
MILLISECONDS
� � � � � � � at
org.apache.hc.core5.io.SocketTimeoutExceptionFactory.create(SocketTimeoutExceptionFactory.java:50)
� � � � � � � at
org.apache.hc.core5.http.impl.nio.AbstractHttp1StreamDuplexer.onTimeout(AbstractHttp1StreamDuplexer.java:378)
� � � � � � � at
org.apache.hc.core5.http.impl.nio.AbstractHttp1IOEventHandler.timeout(AbstractHttp1IOEventHandler.java:81)
� � � � � � � at
org.apache.hc.core5.http.impl.nio.ClientHttp1IOEventHandler.timeout(ClientHttp1IOEventHandler.java:39)
� � � � � � � at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:188)
� � � � � � � at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
� � � � � � � at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:232)
� � � � � � � at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:165)
� � � � � � � at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:127)
� � � � � � � at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:81)
� � � � � � � at
org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
� � � � � � � at java.lang.Thread.run(Thread.java:748)
�
That’s ok, but when we check our statistics the average time in case of a
response timeout is around 1s. For example the above request has been logged
with response timeout:
13:05:35.423,748,http.responseTimeout,13:05:36.171
�
But the total time consumed by this request, since it enters to our app (at
13:05:35.423) until the response is returned (at 13:05:36.171), is just 748ms,
not more than 4s.
�
After making a lot of tests, the solution came disabling keep alive. Our pool
had keep alive enabled (with a value of 20s), disabling keep alive then
everything works fine. Response timeouts almost disappear and when one occurs,
the logged time is around 4s. If we enable keepalive, the issue occurs again.
�
Our KeepAliveStrategy is the same used in asyncClient (changing to the http5
cclasses). It’s set here:
HttpAsyncClientBuilder hcBuilder =
HttpAsyncClients.custom().setKeepAliveStrategy(this.setKeepAliveStrategy(pool.getKeepAliveDuration()))
…
�
And the class is:
�
( … )
public TimeValue getKeepAliveDuration(HttpResponse response, HttpContext
context)
�
{
� // If we have set a keepalive in our pool, it’s used.
� if (this.keepAliveDuration > 0) return
(TimeValue.ofMilliseconds(this.keepAliveDuration));
�
� �// Otherwise search for it in the client response.
� BasicHeaderElementIterator it = new
BasicHeaderElementIterator(response.headerIterator(HTTP.CONN_KEEP_ALIVE));
�
� while (it.hasNext())
� �{
� � HeaderElement he = it.next();
� � String value � � � = he.getValue();
�
� � �if ( (value != null) && (he.getName().equalsIgnoreCase("timeout")) )
� � �{
� � � try { return (TimeValue.ofSeconds(Long.parseLong(value))); }
� � � �catch (NumberFormatException ignore) { break; }
� � }
� }
�
� // Otherwise return '100ms'
� return (TimeValue.ofMilliseconds(100L));
}
�
�
It will be difficult to put traces, we are already in production with this
client. Just let me know what you need, and we will do our best to collect the
info you need.
�
Thanks,
Joan,
�
