You are viewing a plain text version of this content. The canonical link for it is here.
Posted to httpclient-users@hc.apache.org by bnijjhar <ba...@accenture.com> on 2011/06/30 12:32:49 UTC
Threads sometimes wait for unnecessary ~1s to access connections in
pool for HttpClient 4.1.1
Hi
I have implemented a global HttpClient with a ThreadSafeClientConnManager.
The default max connections per route is set to 1. I also set up the URL to
access to be on another machine.
I then create and start 2 threads to call my HttpClient. The first one
completes in a reasonable time; the second one takes a bit too long. When I
analyse the context logs, I see that in the first thread, the time between
the following two messages is very close:
2011-06-29 14:37:56,981 Thread-1 DEBUG
org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
alive indefinitely
2011-06-29 14:37:56,981 Thread-1 DEBUG
org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
connection is reusable.
However, I am consistently seeing a 1 second gap for the second thread
(which was notified at 14:37:56.981 that a connection was now available, as
expected) between these two messages:
2011-06-29 14:37:56,997 Thread-2 DEBUG
org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
alive indefinitely
2011-06-29 14:37:58,169 Thread-2 DEBUG
org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
connection is reusable.
I have tried adding lines such as EntityUtils.consume(entity) and
inputstream.close() but they made no difference (it seems that connections
are released anyway without them according to the debug above).
Could anyone explain this gap? If the URL I connect to is on my local
machine, it doesn't seem to occur ... Obviously, it does mean that my
performance isn't what I'd like it to be (or feel confident in).
--
View this message in context: http://old.nabble.com/Threads-sometimes-wait-for-unnecessary-%7E1s-to-access-connections-in-pool-for-HttpClient-4.1.1-tp31961903p31961903.html
Sent from the HttpClient-User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Threads sometimes wait for unnecessary ~1s to access
connections in pool for HttpClient 4.1.1
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2011-06-30 at 06:27 -0700, bnijjhar wrote:
> Hi Oleg
> The reason for having 1 connection per route and 2 threads created in my
> test is to perform detailed analysis of what happens, then see whether it
> scales up. Obviously harder to debug with more than a few
> threads/connections. I would expect the first thread to create the
> connection, take x ms, then release the connection to the second thread,
> which takes a further y ms to execute ...
>
> I have uploaded sanitized full wire and context log (debug level) with final
> thread times - note the TSCCM 'shutting down' statement, not sure why ...
> anyway it might not be relevant.
>
>
Thread-1 gets a connection immediately as it has been released by
Thread-2. Released by Thread-2 at (13:57:35,595), leased by Thread-1 at
(13:57:35,595)
2011-06-30 13:57:35,595 Thread-2 DEBUG
org.apache.http.impl.conn.tsccm.ConnPoolByRoute - Pooling connection
[HttpRoute[{}->http://RemoteHost:7001]][null]; keep alive indefinitely
2011-06-30 13:57:35,595 Thread-2 DEBUG
org.apache.http.impl.conn.tsccm.ConnPoolByRoute - Notifying thread
waiting on pool [HttpRoute[{}->http://RemoteHost:7001]]
2011-06-30 13:57:35,595 Thread-1 DEBUG
org.apache.http.impl.conn.tsccm.ConnPoolByRoute -
[HttpRoute[{}->http://RemoteHost:7001]] total kept alive: 1, total
issued: 0, total allocated: 1 out of 20
2011-06-30 13:57:35,595 Thread-1 DEBUG
org.apache.http.impl.conn.tsccm.ConnPoolByRoute - Getting free
connection [HttpRoute[{}->http://RemoteHost:7001]][null]
A significant amount of time has been spent consuming the response
content for some reason. See for yourself. The response content was read
into the session buffer at (13:57:35,611), however the connection was
released only at (13:57:36,892)
2011-06-30 13:57:35,611 Thread-1 DEBUG org.apache.http.wire - <<
"<soapenv:Envelope
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"></soapenv:Envelope>"
2011-06-30 13:57:36,892 Thread-1 DEBUG
org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
connection is reusable.
2011-06-30 13:57:36,892 Thread-1 DEBUG
org.apache.http.impl.conn.tsccm.ConnPoolByRoute - Releasing connection
[HttpRoute[{}->http://RemoteHost:7001]][null]
I suspect the time gets wasted somewhere in your code. So far I see no
evidence of HttpClient doing something wrong or being slow.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Threads sometimes wait for unnecessary ~1s to access
connections in pool for HttpClient 4.1.1
Posted by bnijjhar <ba...@accenture.com>.
Hi Oleg
The reason for having 1 connection per route and 2 threads created in my
test is to perform detailed analysis of what happens, then see whether it
scales up. Obviously harder to debug with more than a few
threads/connections. I would expect the first thread to create the
connection, take x ms, then release the connection to the second thread,
which takes a further y ms to execute ...
I have uploaded sanitized full wire and context log (debug level) with final
thread times - note the TSCCM 'shutting down' statement, not sure why ...
anyway it might not be relevant.
olegk wrote:
>
> On Thu, 2011-06-30 at 03:32 -0700, bnijjhar wrote:
>> Hi
>> I have implemented a global HttpClient with a
>> ThreadSafeClientConnManager.
>> The default max connections per route is set to 1. I also set up the URL
>> to
>> access to be on another machine.
>> I then create and start 2 threads to call my HttpClient.
>
> Having two threads and one HTTP connection looks somewhat, well, strange
> to me.
>
>
>> The first one
>> completes in a reasonable time; the second one takes a bit too long. When
>> I
>> analyse the context logs, I see that in the first thread, the time
>> between
>> the following two messages is very close:
>>
>> 2011-06-29 14:37:56,981 Thread-1 DEBUG
>> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
>> alive indefinitely
>> 2011-06-29 14:37:56,981 Thread-1 DEBUG
>> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
>> connection is reusable.
>>
>> However, I am consistently seeing a 1 second gap for the second thread
>> (which was notified at 14:37:56.981 that a connection was now available,
>> as
>> expected) between these two messages:
>>
>> 2011-06-29 14:37:56,997 Thread-2 DEBUG
>> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
>> alive indefinitely
>> 2011-06-29 14:37:58,169 Thread-2 DEBUG
>> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
>> connection is reusable.
>>
>> I have tried adding lines such as EntityUtils.consume(entity) and
>> inputstream.close() but they made no difference (it seems that
>> connections
>> are released anyway without them according to the debug above).
>>
>> Could anyone explain this gap? If the URL I connect to is on my local
>> machine, it doesn't seem to occur ... Obviously, it does mean that my
>> performance isn't what I'd like it to be (or feel confident in).
>
> Post a _complete_ wire / context log of the session.
>
> Oleg
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
>
>
>
http://old.nabble.com/file/p31963089/Debug%2Bfor%2Bforums.txt
Debug+for+forums.txt
--
View this message in context: http://old.nabble.com/Threads-sometimes-wait-for-unnecessary-%7E1s-to-access-connections-in-pool-for-HttpClient-4.1.1-tp31961903p31963089.html
Sent from the HttpClient-User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Threads sometimes wait for unnecessary ~1s to access
connections in pool for HttpClient 4.1.1
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2011-06-30 at 03:32 -0700, bnijjhar wrote:
> Hi
> I have implemented a global HttpClient with a ThreadSafeClientConnManager.
> The default max connections per route is set to 1. I also set up the URL to
> access to be on another machine.
> I then create and start 2 threads to call my HttpClient.
Having two threads and one HTTP connection looks somewhat, well, strange
to me.
> The first one
> completes in a reasonable time; the second one takes a bit too long. When I
> analyse the context logs, I see that in the first thread, the time between
> the following two messages is very close:
>
> 2011-06-29 14:37:56,981 Thread-1 DEBUG
> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
> alive indefinitely
> 2011-06-29 14:37:56,981 Thread-1 DEBUG
> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
> connection is reusable.
>
> However, I am consistently seeing a 1 second gap for the second thread
> (which was notified at 14:37:56.981 that a connection was now available, as
> expected) between these two messages:
>
> 2011-06-29 14:37:56,997 Thread-2 DEBUG
> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
> alive indefinitely
> 2011-06-29 14:37:58,169 Thread-2 DEBUG
> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
> connection is reusable.
>
> I have tried adding lines such as EntityUtils.consume(entity) and
> inputstream.close() but they made no difference (it seems that connections
> are released anyway without them according to the debug above).
>
> Could anyone explain this gap? If the URL I connect to is on my local
> machine, it doesn't seem to occur ... Obviously, it does mean that my
> performance isn't what I'd like it to be (or feel confident in).
Post a _complete_ wire / context log of the session.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Threads sometimes wait for unnecessary ~1s to access
connections in pool for HttpClient 4.1.1
Posted by bnijjhar <ba...@accenture.com>.
Hi Oleg
Thanks for analysing the logs. I never got to the bottom of why it sometimes
takes a while to read all the bytes back. It might be to do with the buffer
size setting? Anyway, I've decided to 'live' with it for now ..
bnijjhar wrote:
>
> Hi
> I have implemented a global HttpClient with a ThreadSafeClientConnManager.
> The default max connections per route is set to 1. I also set up the URL
> to access to be on another machine.
> I then create and start 2 threads to call my HttpClient. The first one
> completes in a reasonable time; the second one takes a bit too long. When
> I analyse the context logs, I see that in the first thread, the time
> between the following two messages is very close:
>
> 2011-06-29 14:37:56,981 Thread-1 DEBUG
> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
> alive indefinitely
> 2011-06-29 14:37:56,981 Thread-1 DEBUG
> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
> connection is reusable.
>
> However, I am consistently seeing a 1 second gap for the second thread
> (which was notified at 14:37:56.981 that a connection was now available,
> as expected) between these two messages:
>
> 2011-06-29 14:37:56,997 Thread-2 DEBUG
> org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
> alive indefinitely
> 2011-06-29 14:37:58,169 Thread-2 DEBUG
> org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager - Released
> connection is reusable.
>
> I have tried adding lines such as EntityUtils.consume(entity) and
> inputstream.close() but they made no difference (it seems that connections
> are released anyway without them according to the debug above).
>
> Could anyone explain this gap? If the URL I connect to is on my local
> machine, it doesn't seem to occur ... Obviously, it does mean that my
> performance isn't what I'd like it to be (or feel confident in).
>
--
View this message in context: http://old.nabble.com/Threads-sometimes-wait-for-unnecessary-%7E1s-to-access-connections-in-pool-for-HttpClient-4.1.1-tp31961903p31987813.html
Sent from the HttpClient-User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org