Return-Path: X-Original-To: apmail-hc-httpclient-users-archive@www.apache.org Delivered-To: apmail-hc-httpclient-users-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 72900D860 for ; Wed, 17 Oct 2012 14:26:39 +0000 (UTC) Received: (qmail 44551 invoked by uid 500); 17 Oct 2012 14:26:39 -0000 Delivered-To: apmail-hc-httpclient-users-archive@hc.apache.org Received: (qmail 44496 invoked by uid 500); 17 Oct 2012 14:26:39 -0000 Mailing-List: contact httpclient-users-help@hc.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: "HttpClient User Discussion" Delivered-To: mailing list httpclient-users@hc.apache.org Received: (qmail 44488 invoked by uid 99); 17 Oct 2012 14:26:39 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 17 Oct 2012 14:26:39 +0000 X-ASF-Spam-Status: No, hits=0.7 required=5.0 tests=SPF_NEUTRAL X-Spam-Check-By: apache.org Received-SPF: neutral (athena.apache.org: local policy) Received: from [217.150.250.48] (HELO kalnich.nine.ch) (217.150.250.48) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 17 Oct 2012 14:26:33 +0000 Received: from [192.168.42.181] (unknown [213.55.184.240]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (No client certificate requested) by kalnich.nine.ch (Postfix) with ESMTPSA id AF11FB801CB for ; Wed, 17 Oct 2012 16:26:10 +0200 (CEST) Message-ID: <1350483966.28939.4.camel@ubuntu> Subject: Re: HttpClient with PoolingClientConnectionManager throws read time out From: Oleg Kalnichevski To: HttpClient User Discussion Date: Wed, 17 Oct 2012 16:26:06 +0200 In-Reply-To: References: <1350414715.2097.13.camel@ubuntu> <001e01cdac70$b4e84d10$1eb8e730$@com> <1350483082.28939.2.camel@ubuntu> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.2.3-0ubuntu6 Content-Transfer-Encoding: 8bit Mime-Version: 1.0 X-Virus-Checked: Checked by ClamAV on apache.org On Wed, 2012-10-17 at 16:19 +0200, Jose Escobar wrote: > 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 just double-checked. -1 is default. Oleg > I'm using httpclient 4.2 > > 2012/10/17 Oleg Kalnichevski : > > 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:eb.jose@gmail.com] > >> 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 : > >> > 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: > >> >> O12101617294288169@xxx.xxxxxxxx.com > >> >> 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 : > >> >> > 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 : > >> >> >> Do you have the wire logs? > >> >> >> > >> >> >> Bill- > >> >> >> > >> >> >> On Mon, Oct 15, 2012 at 7:23 AM, Jose Escobar 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: > >> >> >>> httpclient-users-unsubscribe@hc.apache.org > >> >> >>> For additional commands, e-mail: > >> >> >>> httpclient-users-help@hc.apache.org > >> >> >>> > >> >> >> > >> >> >> ------------------------------------------------------------------ > >> >> >> --- To unsubscribe, e-mail: > >> >> >> httpclient-users-unsubscribe@hc.apache.org > >> >> >> For additional commands, e-mail: > >> >> >> httpclient-users-help@hc.apache.org > >> >> >> > >> >> > >> >> --------------------------------------------------------------------- > >> >> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > >> >> For additional commands, e-mail: httpclient-users-help@hc.apache.org > >> >> > >> > > >> > > >> > > >> > --------------------------------------------------------------------- > >> > To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > >> > For additional commands, e-mail: httpclient-users-help@hc.apache.org > >> > > >> > >> --------------------------------------------------------------------- > >> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > >> For additional commands, e-mail: httpclient-users-help@hc.apache.org > >> > >> > >> --------------------------------------------------------------------- > >> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > >> For additional commands, e-mail: httpclient-users-help@hc.apache.org > >> > > > > > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > > For additional commands, e-mail: httpclient-users-help@hc.apache.org > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org > For additional commands, e-mail: httpclient-users-help@hc.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org For additional commands, e-mail: httpclient-users-help@hc.apache.org