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: Leaking pool entries when using DefaultHttpAsyncClient with PoolingAsyncClientConnectionManager
Date Tue, 14 Feb 2012 19:42:53 GMT
On Tue, 2012-02-14 at 10:45 -0800, Raymond Mak wrote:
> While I was testing DefaultHttpAsyncClient with
> PoolingAsyncClientConnectionManager in the production environment
> (httpasyncclient-4.0-alpha3 + httpcore-4.2-alpha2 +
> httpcore-nio-4.2-alpha2) , I noticed that my application was slowly
> accumulating closed connections in the underlying connection pool as leased
> connections. After digging through the debug log, the following appears to
> be what might be happening to one of the orphaned connections:
> 
> 
> 
> 1.  The (GET) request was successfully sent and the first response packet
> was received with a somewhat larger number of bytes read than what was
> included in the header and the body per the following log entry:
> 
> 
> 
> 2012-02-14 03:05:27,204 [I/O dispatcher 9] DEBUG
> org.apache.http.impl.nio.reactor.IOSessionImpl - http-outgoing-2
> 10.16.1.223:44382<->10.16.99.63:80[ACTIVE][r:r]: 2187 bytes read
> 
> 
> 
> 2.  The headers were successfully parsed per the following log entries:
> 
> 
> 
> 2012-02-14 03:05:27,227 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << HTTP/1.1 200 OK
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << Date: Tue, 14 Feb 2012 03:05:51 GMT
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << Server: Microsoft-IIS/6.0
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << X-Powered-By: ASP.NET
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << X-AspNet-Version: 2.0.50727
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << Cache-Control: private
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << Content-Type: text/plain; charset=utf-8
> 
> 2012-02-14 03:05:27,246 [I/O dispatcher 9] DEBUG org.apache.http.headers -
> http-outgoing-2 << Content-Length: 1965
> 
> 
> 
> and I have verified that the response body was indeed 1965 bytes
> 
> 
> 3. However, it would appear that the protocol handler/decoder didn't
> consider the response stream to be completed according to the following log
> entry:
> 
> 
> 2012-02-14 03:05:27,292 [I/O dispatcher 9] DEBUG
> org.apache.http.nio.protocol.HttpAsyncClientProtocolHandler -
> http-outgoing-2 [ACTIVE] Input ready [content length: 1965; pos: 0;
> completed: false]
> 

This basically means is that the content codec has received zero bytes
out of 1965 expected. By the look of it the server fails to send any
response body at all.

> 
> and so it skipped calling my response handler (and scheduled another
> timeout waiting for more response packets per the following log entry?:
> 
> 
> 2012-02-14 03:05:27,443 [http-apr-8080-exec-62] DEBUG
> org.apache.http.impl.nio.reactor.IOSessionImpl - http-outgoing-2
> 10.16.1.223:44382<->10.16.99.63:80[ACTIVE][rw:r]: Event set [w])
> 
> 
> 4. Eventually a timeout occurred, but it appeared that my response handler
> was skipped, again and the connection was closed without it being released
> back to the pool as far as I can tell from the following log entries:
> 

Could you please try to reproduce the problem with the latest SVN
snapshot and if the problem persists raise a JIRA for this issue and
attach a complete wire / context log of the session?

Cheers

Oleg

PS: and please subscribe to the list.

> 
> 2012-02-14 03:05:28,136 [I/O dispatcher 9] DEBUG
> org.apache.http.nio.protocol.HttpAsyncClientProtocolHandler -
> http-outgoing-2 [ACTIVE] Timeout
> 2012-02-14 03:05:28,137 [I/O dispatcher 9] DEBUG
> org.apache.http.impl.nio.reactor.IOSessionImpl - http-outgoing-2
> 10.16.1.223:44382<->10.16.99.63:80[ACTIVE][rw:r]: Close
> 2012-02-14 03:05:28,137 [I/O dispatcher 9] DEBUG
> org.apache.http.nio.protocol.HttpAsyncClientProtocolHandler -
> http-outgoing-2 [CLOSED]: Disconnected
> 
> 
> Given that I do have access to the source code, I am fully prepared to dig
> through this further. But before going to the deep end, I thought I would
> send this out in case someone knew something about this already and/or
> suggestions on how to track this down quicker.
> 
> 
> Thanks much,
> 
> 
> -Raymond



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