Hello,

On 01/30/2014 05:15 PM, Oleg Kalnichevski wrote:
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
Got it now. Sorry, I'm not that familiar with this code.

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.
No need from my standpoint now that I understand it's OK.

* 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
OK. Got it.

Hope this helps
A lot. Thank you very much for your time, help and awesome contribution to the community.

A.


Oleg



---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org


--
Antoine Bonavita (anto...@stickyads.tv) - CTO StickyADS.tv
Tel: +33 6 72 78 76 31/+33 9 50 68 21 32
Envoyé de mon PC. Moi je suis Fedora.

---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org

Reply via email to