[prev in list] [next in list] [prev in thread] [next in thread] 

List:       httpclient-users
Subject:    Re: Leaking pool entries when using DefaultHttpAsyncClient with PoolingAsyncClientConnectionManager
From:       Raymond Mak <raymond468 () gmail ! com>
Date:       2012-02-15 6:19:55
Message-ID: CAHFd4KhcKVpzrSi=dYQYdAgtQ+1WhNpK8HOQwuFCCY8fmzENOg () mail ! gmail ! com
[Download RAW message or body]


Just want to send a follow-up that the issue seems to have disappeared once
I have upgraded to the latest snapshot of all httpcomponents per Oleg's
suggestions. Thanks!

Raymond

On Tue, Feb 14, 2012 at 10:45 AM, Raymond Mak <raymond468@gmail.com> 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]
>
>
> 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:
>
>
> 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
>


[prev in list] [next in list] [prev in thread] [next in thread]