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]
