Ok, I guess this is MAX_INT and it could means keep-alive indefinitely, but how can it get this value if I had override DefaultConnectionKeepAliveStrategy to set 15000 ms keep-alive??
Maybe is super.getKeepAliveDuration(response, context); returning MAX_INT and it is not getting inside the if(keepAlive==-1) ?? I'm using httpclient 4.2 2012/10/17 Oleg Kalnichevski <[email protected]>: > On Wed, 2012-10-17 at 10:07 -0400, Mark Claassen wrote: >> A quick check using an online too shows that that 9223372036854775807 is >> 111111111111111111111111111111111111111111111111111111111111111 in binary. >> > > Yeah, it is just bad logging. Basically that value means keep alive > indefinitely. I thought I had fixed all the instances of that problem. > Apparently not. > > Oleg > >> -----Original Message----- >> From: Jose Escobar [mailto:[email protected]] >> Sent: Wednesday, October 17, 2012 5:24 AM >> To: HttpClient User Discussion >> Subject: Re: HttpClient with PoolingClientConnectionManager throws read time >> out >> >> I have 60 seconds of timeout, not to aggressive. Maybe it's a limit on my >> gnu/linux on outgoing sockets or something like this. >> >> However I found a strange value for keep-alive time on logs: >> >> o.a.h.i.c.PoolingClientConnectionManager - Connection [id: 220][route: >> {}->http://yyyyyy.com] can be kept alive for 9223372036854775807 MILLISECONDS >> >> This time wasn't at request header and I have a limit of 15 secs when no >> keep-alive time header is received: >> >> httpClient.setKeepAliveStrategy(new DefaultConnectionKeepAliveStrategy() { >> @Override >> public long getKeepAliveDuration( >> HttpResponse response, >> HttpContext context) { >> long keepAlive = super.getKeepAliveDuration(response, >> context); >> if (keepAlive == -1) { >> keepAlive = 15000; >> } >> return keepAlive; >> } >> >> }); >> >> >> It's that normal? >> >> 2012/10/16 Oleg Kalnichevski <[email protected]>: >> > On Tue, 2012-10-16 at 17:58 +0200, Jose Escobar wrote: >> >> Finally I've captured the wire log of the anomalous situation. There >> >> are multiple executors (threads) trying to send different http posts >> >> to the same url and all get the same exception: >> >> >> > >> > Jose >> > >> > The thing is I/O socket operations as well as socket timeouts are all >> > handled by the JRE through native calls. So, essentially, i/o >> > operations can only time out when the server fails to send data within >> > the specified timeout period. Either your timeout settings are too >> > aggressive or something happens on the server side that prevents it >> > from serving requests. >> > >> > Oleg >> > >> >> 2012-16-10_17:30:30.668 [myExecutor-45] INFO >> >> c.e.e.a.l.a.i.As2MessageBuilderImpl - Añadir messageid: >> >> [email protected] >> >> 2012-16-10_17:30:30.766 [myExecutor-45] INFO >> >> c.e.e.a.l.a.i.As2MessageSenderImpl - Enviando mensaje HTTP POST >> >> 2012-16-10_17:30:30.766 [myExecutor-45] DEBUG >> >> o.a.h.i.c.PoolingClientConnectionManager - Connection request: [route: >> >> {}->http://yyyyyy.com][total kept alive: 52; route allocated: 44 of >> >> 75; total allocated: 96 of 400] >> >> 2012-16-10_17:30:30.766 [myExecutor-45] DEBUG >> >> o.a.h.i.c.PoolingClientConnectionManager - Connection leased: [id: >> >> 220][route: {}->http://yyyyyy.com][total kept alive: 52; route >> >> allocated: 45 of 75; total allocated: 97 of 400] >> >> 2012-16-10_17:30:30.766 [myExecutor-45] DEBUG >> >> o.a.h.i.c.DefaultClientConnectionOperator - Connecting to >> >> yyyyyy.com:80 >> >> 2012-16-10_17:30:30.766 [myExecutor-45] INFO >> >> c.e.e.a.c.CustomPlainSocketFactory - Tratando de conseguir un socket >> >> de salida con puerto 52926 >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.c.protocol.RequestAddCookies - CookieSpec selected: best-match >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.c.protocol.RequestAddCookies - Cookie [version: 0][name: >> >> ASP.NET_SessionId][value: cd5gazy1mzkrx2arlbpqyfe5][domain: >> >> yyyyyy.com][path: /][expiry: null] match [yyyyyy.com:80/var/foo.aspx] >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.c.protocol.RequestAuthCache - Auth cache not set in the context >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.c.p.RequestTargetAuthentication - Target auth state: >> >> UNCHALLENGED >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.c.p.RequestProxyAuthentication - Proxy auth state: UNCHALLENGED >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.impl.client.DefaultHttpClient - Attempt 1 to execute request >> >> 2012-16-10_17:30:30.801 [myExecutor-45] DEBUG >> >> o.a.h.i.conn.DefaultClientConnection - Sending request: POST >> >> /var/foo.aspx HTTP/1.1 >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> POST /var/foo.aspx HTTP/1.1 >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> MIME-Version: 1.0 >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Content-Type: application/pkcs7-mime; name="smime.p7m"; >> >> smime-type=enveloped-data >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Content-Transfer-Encoding: binary >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Content-Disposition: attachment; filename="smime.p7m" >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Content-Description: S/MIME Encrypted Message >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Content-Length: 12459 >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Host: yyyyyy.com >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Connection: Keep-Alive >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> User-Agent: Apache-HttpClient/4.2 (java 1.5) >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Cookie: ASP.NET_SessionId=cd5gazy1mzkrx2arlbpqyfe5 >> >> 2012-16-10_17:30:30.802 [myExecutor-45] DEBUG org.apache.http.headers >> >> - >> Cookie2: $Version=1 >> >> ... >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.conn.DefaultClientConnection - Connection >> >> 0.0.0.0:52926<->xxx.xxx.xxx.xxx closed >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.impl.client.DefaultHttpClient - Closing the connection. >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.conn.DefaultClientConnection - Connection >> >> 0.0.0.0:52926<->xxx.xxx.xxx.xxx closed >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.conn.DefaultClientConnection - Connection >> >> 0.0.0.0:52926<->xxx.xxx.xxx.xxx shut down >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.c.PoolingClientConnectionManager - Connection [id: 220][route: >> >> {}->http://yyyyyy.com] can be kept alive for 9223372036854775807 >> >> MILLISECONDS >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.conn.DefaultClientConnection - Connection >> >> 0.0.0.0:52926<->xxx.xxx.xxx.xxx closed >> >> 2012-16-10_17:31:30.821 [myExecutor-45] DEBUG >> >> o.a.h.i.c.PoolingClientConnectionManager - Connection released: [id: >> >> 220][route: {}->http://yyyyyy.com][total kept alive: 52; route >> >> allocated: 48 of 75; total allocated: 100 of 400] >> >> 2012-16-10_17:31:30.821 [myExecutor-45] INFO >> >> c.e.e.a.l.a.i.As2MessageSenderImpl - Enviado mensaje hacia >> >> http://yyyyyy.com/var/foo.aspx pero ocurrió un error: Read timed out >> >> >> >> >> >> >> >> >> >> I don't think that external server is just too slow to respond >> >> because almost every time it tooks less than 4 seconds to respond. >> >> >> >> 2012/10/16 Jose Escobar <[email protected]>: >> >> > Murphy's law, since I activated wire log there's no timeout errors... >> >> > >> >> > As soon as I get an error I'll mail it >> >> > >> >> > >> >> > 2012/10/15 William Speirs <[email protected]>: >> >> >> Do you have the wire logs? >> >> >> >> >> >> Bill- >> >> >> >> >> >> On Mon, Oct 15, 2012 at 7:23 AM, Jose Escobar <[email protected]> >> >> >> wrote: >> >> >>> Hello, >> >> >>> >> >> >>> I'm using httpclient on a spring aplication to send http posts. >> >> >>> I have a shared singleton bean instance of DefaultHttpClient that >> >> >>> I use to execute httpPost, this DefaultHttpClient have a >> >> >>> PoolingClientConnectionManager and it's configured as show : >> >> >>> >> >> >>> ... >> >> >>> PoolingClientConnectionManager connectionManager=new >> >> >>> PoolingClientConnectionManager(schemeRegistry, 65, >> >> >>> java.util.concurrent.TimeUnit.SECONDS); >> >> >>> >> >> >>> // Increase max total connection to 100 >> >> >>> connectionManager.setMaxTotal(100); >> >> >>> // Increase default max connection per route to 15 >> >> >>> connectionManager.setDefaultMaxPerRoute(25); >> >> >>> // Increase max connections for localhost:80 to 50 HttpHost >> >> >>> localhost = new HttpHost("locahost", 80); >> >> >>> connectionManager.setMaxPerRoute(new HttpRoute(localhost), 50); >> >> >>> >> >> >>> ... >> >> >>> >> >> >>> @Bean >> >> >>> public DefaultHttpClient httpClient(){ DefaultHttpClient >> >> >>> httpClient=new DefaultHttpClient(connectionManager()); >> >> >>> //httpClient.setParams(params) >> >> >>> >> >> >>> HttpParams params = httpClient.getParams(); >> >> >>> HttpConnectionParams.setConnectionTimeout(params, >> >> >>> HTTPCLIENT_TIMEOUT); HttpConnectionParams.setSoTimeout(params, >> >> >>> HTTPCLIENT_TIMEOUT); >> >> >>> >> >> >>> return httpClient; >> >> >>> } >> >> >>> >> >> >>> >> >> >>> >> >> >>> It works correctly until the aplication have to send multiple >> >> >>> post at same time to the same route. It start to throws >> >> >>> readTimeOut Exception >> >> >>> >> >> >>> java.net.SocketTimeoutException: Read timed out at >> >> >>> java.net.SocketInputStream.socketRead0(Native Method) at >> >> >>> java.net.SocketInputStream.read(SocketInputStream.java:129) >> >> >>> at >> >> >>> org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(Abs >> >> >>> tractSessionInputBuffer.java:166) at >> >> >>> org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputB >> >> >>> uffer.java:90) at >> >> >>> org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(Abstr >> >> >>> actSessionInputBuffer.java:281) at >> >> >>> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(Def >> >> >>> aultHttpResponseParser.java:92) at >> >> >>> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(Def >> >> >>> aultHttpResponseParser.java:61) at >> >> >>> org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessa >> >> >>> geParser.java:254) at >> >> >>> org.apache.http.impl.AbstractHttpClientConnection.receiveResponse >> >> >>> Header(AbstractHttpClientConnection.java:289) >> >> >>> at >> >> >>> org.apache.http.impl.conn.DefaultClientConnection.receiveResponse >> >> >>> Header(DefaultClientConnection.java:252) >> >> >>> at >> >> >>> org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResp >> >> >>> onseHeader(ManagedClientConnectionImpl.java:191) >> >> >>> at >> >> >>> org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(Ht >> >> >>> tpRequestExecutor.java:300) at >> >> >>> org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestE >> >> >>> xecutor.java:127) at >> >> >>> org.apache.http.impl.client.DefaultRequestDirector.tryExecute(Def >> >> >>> aultRequestDirector.java:713) at >> >> >>> org.apache.http.impl.client.DefaultRequestDirector.execute(Defaul >> >> >>> tRequestDirector.java:518) at >> >> >>> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHt >> >> >>> tpClient.java:906) at >> >> >>> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHt >> >> >>> tpClient.java:805) at >> >> >>> com.edicom.edicomnet.asxserver.logic.as2.impl.As2MessageSenderImp >> >> >>> l.sendMessage(As2MessageSenderImpl.java:117) >> >> >>> at sun.reflect.GeneratedMethodAccessor575.invoke(Unknown Source) >> >> >>> at >> >> >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodA >> >> >>> ccessorImpl.java:25) at >> >> >>> java.lang.reflect.Method.invoke(Method.java:597) >> >> >>> at >> >> >>> org.springframework.aop.support.AopUtils.invokeJoinpointUsingRefl >> >> >>> ection(AopUtils.java:309) at >> >> >>> org.springframework.aop.framework.ReflectiveMethodInvocation.invo >> >> >>> keJoinpoint(ReflectiveMethodInvocation.java:183) >> >> >>> at >> >> >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proc >> >> >>> eed(ReflectiveMethodInvocation.java:150) >> >> >>> at >> >> >>> org.springframework.transaction.interceptor.TransactionIntercepto >> >> >>> r.invoke(TransactionInterceptor.java:110) >> >> >>> at >> >> >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proc >> >> >>> eed(ReflectiveMethodInvocation.java:172) >> >> >>> at >> >> >>> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDy >> >> >>> namicAopProxy.java:202) at $Proxy52.sendMessage(Unknown Source) >> >> >>> at >> >> >>> com.edicom.edicomnet.asxserver.businessServices.impl.MessageSende >> >> >>> rImpl.sendCreatedAS2Message(MessageSenderImpl.java:119) >> >> >>> at sun.reflect.GeneratedMethodAccessor551.invoke(Unknown Source) >> >> >>> at >> >> >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodA >> >> >>> ccessorImpl.java:25) at >> >> >>> java.lang.reflect.Method.invoke(Method.java:597) >> >> >>> at >> >> >>> org.springframework.aop.support.AopUtils.invokeJoinpointUsingRefl >> >> >>> ection(AopUtils.java:309) at >> >> >>> org.springframework.aop.framework.ReflectiveMethodInvocation.invo >> >> >>> keJoinpoint(ReflectiveMethodInvocation.java:183) >> >> >>> at >> >> >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proc >> >> >>> eed(ReflectiveMethodInvocation.java:150) >> >> >>> at >> >> >>> org.springframework.aop.interceptor.AsyncExecutionInterceptor$1.c >> >> >>> all(AsyncExecutionInterceptor.java:80) >> >> >>> at >> >> >>> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303 >> >> >>> ) at java.util.concurrent.FutureTask.run(FutureTask.java:138) >> >> >>> at >> >> >>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPool >> >> >>> Executor.java:886) at >> >> >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExec >> >> >>> utor.java:908) at java.lang.Thread.run(Thread.java:662) >> >> >>> >> >> >>> >> >> >>> I hope you can help me with this problem (maybe something about >> >> >>> concurrency?) >> >> >>> >> >> >>> >> >> >>> Thank you! >> >> >>> >> >> >>> ----------------------------------------------------------------- >> >> >>> ---- To unsubscribe, e-mail: >> >> >>> [email protected] >> >> >>> For additional commands, e-mail: >> >> >>> [email protected] >> >> >>> >> >> >> >> >> >> ------------------------------------------------------------------ >> >> >> --- To unsubscribe, e-mail: >> >> >> [email protected] >> >> >> For additional commands, e-mail: >> >> >> [email protected] >> >> >> >> >> >> >> --------------------------------------------------------------------- >> >> To unsubscribe, e-mail: [email protected] >> >> For additional commands, e-mail: [email protected] >> >> >> > >> > >> > >> > --------------------------------------------------------------------- >> > To unsubscribe, e-mail: [email protected] >> > For additional commands, e-mail: [email protected] >> > >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
