hc-httpclient-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Oleg Kalnichevski <ol...@apache.org>
Subject Re: HttpClient with PoolingClientConnectionManager throws read time out
Date Wed, 17 Oct 2012 14:26:06 GMT
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 <olegk@apache.org>:
> > 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 <olegk@apache.org>:
> >> > 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 <eb.jose@gmail.com>:
> >> >> > 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 <wspeirs@apache.org>:
> >> >> >> Do you have the wire logs?
> >> >> >>
> >> >> >> Bill-
> >> >> >>
> >> >> >> On Mon, Oct 15, 2012 at 7:23 AM, Jose Escobar <eb.jose@gmail.com>
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


Mime
View raw message