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: Weird leasing/releasing sequence leading to close
Date Thu, 30 Jan 2014 16:15:37 GMT
On Thu, 2014-01-30 at 15:59 +0100, Antoine Bonavita wrote:
> Hello,
> 
> On 01/30/2014 01:43 PM, Oleg Kalnichevski wrote:
> > On Thu, 2014-01-30 at 13:07 +0100, Antoine Bonavita wrote:
> >> Hello,
> >>
> >> I'm investigating an issue with our application (it intermittently stops
> >> responding and we have to restart it).
> >>
> >> To give you a bit of background, it's a Tomcat7 application using
> >> AsyncServlet and connecting to a number of other servers using HTTP as a
> >> transport layer (for each HTTP request we get, we do 3 to 5 requests in
> >> parallel to the upstream servers). Of course, we are using
> >> http-components and more specifically http-async-client for the
> >> communication to the upstream servers.
> >> We are using: httpasynclient-4.0, httpclient-4.3.2, httpcore-4.3.1 and
> >> httpcore-nio-4.3.2-20140116 (that's 4.3.2 with the fix for
> >> https://issues.apache.org/jira/browse/HTTPCORE-370).
> >>
> >> My current investigation led me to enable logging at the connection
> >> level and look at some of the connections.
> >>
> >> You will find attached the logs for a specific connection
> >> (http-outgoing-601). There are two things that "look wierd" to me but
> >> I'm not at all an expert so I would like to have your point of view:
> >> * The connection is leased at 18:54:52,988, then again at 18:54:56,660.
> >> After that it is released at 18:54:56,682 and at 18:55:00,394. To me,
> >> one http-outgoing should be released before it can be leased again. Am I
> >> missing something ?
> >
> > Connection pool logging takes place outside of the pool lock. Under
> > certain conditions the connection being released can get grabbed almost
> > immediately by another thread. As a result log entries may look mixed
> > up. However, as you can see the second 'release' entry is preceded by
> > 'west.tubemogul.com:80] can be kept alive indefinitely' entry. This
> > basically means the connection was in the process of being released at
> > the same time.
> I understand what you are saying. However, this is the same thread. We 
> include in our log files the name of the thread after the severity and 
> all logs have the thread name "I/O dispatcher 6". Did I miss something ?
> 

It is the same story. The lease request callback gets executed before
the release operation is fully completed. 

http://hc.apache.org/httpcomponents-asyncclient-4.0.x/httpasyncclient/xref/org/apache/http/impl/nio/conn/PoolingNHttpClientConnectionManager.html#456

If you think this is a problem please raise a JIRA and i'll try to tweak
the logging to make it appear more deterministic.   

> 
> >> * At 18:55:00,384, I see a "-1 bytes read" which seems to trigger a
> >> close. What could be causing this ?
> >>
> >
> > The opposite endpoint closing the connection on its end, for whatever
> > reason.
> OK. That makes sense. Is there an easy way (i.e. without enabling 
> logging at the wire level) to distinguish between the two situations:
> 1 - Opposite end closed the connection at the end of an HTTP answer.
> 2 - Opposite end closed the connection in the middle of an HTTP answer.
> 

This distinction is made by the protocol handler
http://hc.apache.org/httpcomponents-core-4.3.x/httpcore-nio/xref/org/apache/http/nio/protocol/HttpAsyncRequestExecutor.html#243

In the former case the protocol handler should recover gracefully. In
the latter case the request producer and response consumer should
receive ConnectionClosedException exception through their #failed
methods by way of #failed method of the exchange handler.

http://hc.apache.org/httpcomponents-asyncclient-4.0.x/httpasyncclient/xref/org/apache/http/impl/nio/client/DefaultClientExchangeHandlerImpl.html#187

Hope this helps

Oleg



---------------------------------------------------------------------
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