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 Joan Balagueró <jo...@grupoventus.com> on 2016/03/15 15:54:29 UTC

Help with async client

Hello,

 

We have moved from the blocking client (PoolingHttpClientConnectionManager)
to the async one (PoolingNHttpClientConnectionManager), and we are starting
some tests to check performance.

 

We have a test app that sends xml requests to our proxy. If the response is
not found in cache,  the proxy uses the http client to get the responses
from the back end. 

 

Starting 20 threads, with the blocking client we reach about 700 requests
per second.

 

With the async client, the pattern we are seeing is: 20 requests are
processed, then a 5 second pause, then 20 more requests processed, 5 second
pause, etc.

 

Obviously we have something misconfigured in our async pool. We though that
the problem could come from the max htttp connections allowed, but checking
the log:

 

[exchange: 2537] start execution

[exchange: 2537] Request connection for {}->http://10.20.30.246:80

Connection request: [route: {}->http://10.20.30.246:80][total kept alive: 0;
route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]

Connection leased: [id: http-outgoing-209][route:
{}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of
2147483647; total allocated: 1 of 2147483647]

[exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209
[ACTIVE]}

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set
attribute http.nio.exchange-handler

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Event
set [w]

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
timeout 50000

http-outgoing-209 [ACTIVE]: Connected

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
attribute http.nio.http-exchange-state

Start connection routing

Connection route established

[exchange: 2537] Attempt 1 to execute request

Target auth state: UNCHALLENGED

Proxy auth state: UNCHALLENGED

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
timeout 1000

http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1

http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
charset=ISO-8859-1

http-outgoing-209 >> host: ws.rhodasol.es

http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1 (Java/1.7.0_75)

http-outgoing-209 >> x-ventusproxy-id:
bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbHwyMDA4
MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi5jb3Vu
dHJ5MzF8MjM

uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5jaXR5fDI
zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb25UeXB
lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc

mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnwyNC58M
jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU5LTE=

http-outgoing-209 >> x-forwarded-for: 192.168.1.29

http-outgoing-209 >> Content-Length: 1368

http-outgoing-209 >> Connection: Keep-Alive

http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Event
set [w]

http-outgoing-209 [ACTIVE] Output ready

[exchange: 2537] produce content

[exchange: 2537] Request completed

 

(etc).

 

I can send more information about this log and our pool configuration. But
since the pattern is so clear, maybe someone has experienced something
similar and can tell me what’s wrong.

 

I suppose that the following is not related with this issue, but we have and
idleConnectionHandler that is executed every 5 seconds.

 

Thanks,

 

Joan.

Re: Help with async client

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2016-03-17 at 17:51 +0100, Joan Balagueró wrote:
> Hello,
> 
> I hope this is the last question ... On our proxy we are reading the response from the backend with a FutureCallback<HttpResponse>. On the complete method, we process the response body in this way:
> 
> public void completed(HttpResponse objResponse) 
> {
>  HttpEntity entity	= null;
> 	  
>  try
>  {
>  entity				= objResponse.getEntity();
>  int contentLength		= (int)entity.getContentLength(); 
>  ByteArrayOutputStream baos	= new ByteArrayOutputStream(contentLength > 0 ? contentLength : this.bufferHttpRespuestas);
> 
>  Bis				= new BufferedInputStream(entity.getContent(), this.bufferHttpRespuestas); 
>  byte[] tmp			= new byte[this.bufferHttpRespuestas];
>  int numBytesRead;
>  
>  while ((numBytesRead = bis.read(tmp)) >= 0) baos.write(tmp, 0, numBytesRead);
>  ( . . .)
> 
> 
> The response is read from the inputstream contained in 'objHttpResponse', this response is already read so no network calls here (we read locally from the ' objResponse' object).
> Reading the body in this way, am I storing this body twice, one in the ' objResponse' and another in the 'baos' variable?
> 
> In the link to the benchmark you sent me, a HttpAsyncResponseConsumer is used, so the content is processed in chunks on the  consumeContent method (and I understand that the 'responseReceived' method is called once the headers have been processed).
> 
> So the point is: is one of these methods better taking into account that my responses can be really large and I always need to store them in memory for further processing?
>  

HttpAsyncRequestProducer and HttpAsyncResponseConsumer is the only
resource efficient way to transmit large messages with HttpAsyncClient.

Oleg


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

RE: Help with async client

Posted by Joan Balagueró <jo...@grupoventus.com>.
Hello,

I hope this is the last question ... On our proxy we are reading the response from the backend with a FutureCallback<HttpResponse>. On the complete method, we process the response body in this way:

public void completed(HttpResponse objResponse) 
{
 HttpEntity entity	= null;
	  
 try
 {
 entity				= objResponse.getEntity();
 int contentLength		= (int)entity.getContentLength(); 
 ByteArrayOutputStream baos	= new ByteArrayOutputStream(contentLength > 0 ? contentLength : this.bufferHttpRespuestas);

 Bis				= new BufferedInputStream(entity.getContent(), this.bufferHttpRespuestas); 
 byte[] tmp			= new byte[this.bufferHttpRespuestas];
 int numBytesRead;
 
 while ((numBytesRead = bis.read(tmp)) >= 0) baos.write(tmp, 0, numBytesRead);
 ( . . .)


The response is read from the inputstream contained in 'objHttpResponse', this response is already read so no network calls here (we read locally from the ' objResponse' object).
Reading the body in this way, am I storing this body twice, one in the ' objResponse' and another in the 'baos' variable?

In the link to the benchmark you sent me, a HttpAsyncResponseConsumer is used, so the content is processed in chunks on the  consumeContent method (and I understand that the 'responseReceived' method is called once the headers have been processed).

So the point is: is one of these methods better taking into account that my responses can be really large and I always need to store them in memory for further processing?
 
Thanks,

Joan.

-----Mensaje original-----
De: Oleg Kalnichevski [mailto:olegk@apache.org] 
Enviado el: jueves, 17 de marzo de 2016 10:50
Para: HttpClient User Discussion
Asunto: Re: Help with async client

On Thu, 2016-03-17 at 10:42 +0100, Joan Balagueró wrote:
> Hi Oleg,
> 
> Thanks. If I have a 400ms connection timeout and a 850ms response timeout, I understand that the select interval must contain the 400ms (the lowest value). True?
> 

Yes.

> In our app these connection/response timeouts can be modified on the fly. That's why we are using a request config, and for each request we perform a copy of the default request config and replace the values for connect/response timeout.
> 
> So, the select interval should also be modified in this case. Is this possible with the 'PoolingNHttpClientConnectionManager' already created? 

No.

> Because  I don't see any method to get the IOReactor config from the nio pool.
> 

Oleg


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




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

Re: Help with async client

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2016-03-17 at 10:42 +0100, Joan Balagueró wrote:
> Hi Oleg,
> 
> Thanks. If I have a 400ms connection timeout and a 850ms response timeout, I understand that the select interval must contain the 400ms (the lowest value). True?
> 

Yes.

> In our app these connection/response timeouts can be modified on the fly. That's why we are using a request config, and for each request we perform a copy of the default request config and replace the values for connect/response timeout.
> 
> So, the select interval should also be modified in this case. Is this possible with the 'PoolingNHttpClientConnectionManager' already created? 

No.

> Because  I don't see any method to get the IOReactor config from the nio pool.
> 

Oleg


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

RE: Help with async client

Posted by Joan Balagueró <jo...@grupoventus.com>.
Hi Oleg,

Thanks. If I have a 400ms connection timeout and a 850ms response timeout, I understand that the select interval must contain the 400ms (the lowest value). True?

In our app these connection/response timeouts can be modified on the fly. That's why we are using a request config, and for each request we perform a copy of the default request config and replace the values for connect/response timeout.

So, the select interval should also be modified in this case. Is this possible with the 'PoolingNHttpClientConnectionManager' already created? Because  I don't see any method to get the IOReactor config from the nio pool.

Thanks,

Joan.

-----Mensaje original-----
De: Oleg Kalnichevski [mailto:olegk@apache.org] 
Enviado el: miércoles, 16 de marzo de 2016 16:22
Para: HttpClient User Discussion
Asunto: Re: Help with async client

On Wed, 2016-03-16 at 15:41 +0100, Joan Balagueró wrote:
> Hi Oleg,
> 
> Finally the issue was nothing to do with the async client.
> 
> Now we are experimenting with connection and response timeouts, setting just 1ms for both. In the blocking client, we get connection and response timeouts for all requests we send.
> But with the async client we are not able to get any exception, all requests are processed normally and all responses are obtained from the backend.
> 

The smallest granularity for I/O timeouts by default is 1 second. One
can reduce it by setting lower value of IOReactorConfig#selectInterval
at the cost of higher CPU utilization.

Oleg

> Checking the log:
> [exchange: 1] start execution
> [exchange: 1] Request connection for {}->http://10.20.30.246:80
> Connection request: [route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
> Connection leased: [id: http-outgoing-0][route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 2147483647; total allocated: 1 of 2147483647]
> [exchange: 1] Connection allocated: CPoolProxy{http-outgoing-0 [ACTIVE]}
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][r:]: Set attribute http.nio.exchange-handler
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Event set [w]
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1   <--- CONNECTION TIMEOUT?
> http-outgoing-0 [ACTIVE]: Connected
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set attribute http.nio.http-exchange-state
> Start connection routing
> Connection route established
> [exchange: 1] Attempt 1 to execute request
> Target auth state: UNCHALLENGED
> Proxy auth state: UNCHALLENGED
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1 <-- RESPONSE TIMEOUT?
> http-outgoing-0 >> POST /wsserhs/rhodasol HTTP/1.1
> http-outgoing-0 >> content-type: application/x-www-form-urlencoded; charset=ISO-8859-1
> http-outgoing-0 >> host: ws.rhodasol.es
> ( . . . )
> 
> It seems the values are correct, 1ms for both connection and response timeouts. Any response from the bakcend takes 100ms at least, because a Thread.sleep(100) is set before writing any byte to the servletoutputstream.
> 
> So, why are these exceptions not triggered?
> 
> Thanks,
> Joan.
> 
> 
> 
> 
> -----Mensaje original-----
> De: Oleg Kalnichevski [mailto:olegk@apache.org] 
> Enviado el: martes, 15 de marzo de 2016 16:14
> Para: HttpClient User Discussion
> Asunto: Re: Help with async client
> 
> On Tue, 2016-03-15 at 15:54 +0100, Joan Balagueró wrote:
> > Hello,
> > 
> >  
> > 
> > We have moved from the blocking client 
> > (PoolingHttpClientConnectionManager)
> > to the async one (PoolingNHttpClientConnectionManager), and we are 
> > starting some tests to check performance.
> > 
> >  
> > 
> > We have a test app that sends xml requests to our proxy. If the 
> > response is not found in cache,  the proxy uses the http client to get 
> > the responses from the back end.
> > 
> >  
> > 
> > Starting 20 threads, with the blocking client we reach about 700 
> > requests per second.
> > 
> >  
> > 
> > With the async client, the pattern we are seeing is: 20 requests are 
> > processed, then a 5 second pause, then 20 more requests processed, 5 
> > second pause, etc.
> > 
> >  
> > 
> > Obviously we have something misconfigured in our async pool. We though 
> > that the problem could come from the max htttp connections allowed, 
> > but checking the log:
> > 
> >  
> > 
> > [exchange: 2537] start execution
> > 
> > [exchange: 2537] Request connection for {}->http://10.20.30.246:80
> > 
> > Connection request: [route: {}->http://10.20.30.246:80][total kept 
> > alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 
> > 2147483647]
> > 
> > Connection leased: [id: http-outgoing-209][route:
> > {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 
> > 2147483647; total allocated: 1 of 2147483647]
> > 
> > [exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209 
> > [ACTIVE]}
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set 
> > attribute http.nio.exchange-handler
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Event set [w]
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set timeout 50000
> > 
> > http-outgoing-209 [ACTIVE]: Connected
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set attribute http.nio.http-exchange-state
> > 
> > Start connection routing
> > 
> > Connection route established
> > 
> > [exchange: 2537] Attempt 1 to execute request
> > 
> > Target auth state: UNCHALLENGED
> > 
> > Proxy auth state: UNCHALLENGED
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set timeout 1000
> > 
> > http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1
> > 
> > http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
> > charset=ISO-8859-1
> > 
> > http-outgoing-209 >> host: ws.rhodasol.es
> > 
> > http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1 
> > (Java/1.7.0_75)
> > 
> > http-outgoing-209 >> x-ventusproxy-id:
> > bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbH
> > wyMDA4 
> > MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi
> > 5jb3Vu
> > dHJ5MzF8MjM
> > 
> > uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5ja
> > XR5fDI 
> > zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb
> > 25UeXB lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc
> > 
> > mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnw
> > yNC58M 
> > jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU
> > 5LTE=
> > 
> > http-outgoing-209 >> x-forwarded-for: 192.168.1.29
> > 
> > http-outgoing-209 >> Content-Length: 1368
> > 
> > http-outgoing-209 >> Connection: Keep-Alive
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Event set [w]
> > 
> > http-outgoing-209 [ACTIVE] Output ready
> > 
> > [exchange: 2537] produce content
> > 
> > [exchange: 2537] Request completed
> > 
> >  
> > 
> > (etc).
> > 
> >  
> > 
> > I can send more information about this log and our pool configuration. 
> > But since the pattern is so clear, maybe someone has experienced 
> > something similar and can tell me what’s wrong.
> > 
> >  
> > 
> > I suppose that the following is not related with this issue, but we 
> > have and idleConnectionHandler that is executed every 5 seconds.
> > 
> >  
> > 
> > Thanks,
> > 
> >  
> > 
> > Joan.
> > 
> >  
> 
> Consider simplifying your application / configuration to something very basic, then start adding more complexity and see at which point the problem starts occurring.
> 
> You can take with this benchmark as a starting point 
> 
> http://svn.apache.org/repos/asf/httpcomponents/benchmark/httpclient/trunk/src/main/java/org/apache/http/client/benchmark/ApacheHttpAsyncClient.java
> 
> Oleg
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
> 
> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
> 



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




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

Re: Help with async client

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Wed, 2016-03-16 at 15:41 +0100, Joan Balagueró wrote:
> Hi Oleg,
> 
> Finally the issue was nothing to do with the async client.
> 
> Now we are experimenting with connection and response timeouts, setting just 1ms for both. In the blocking client, we get connection and response timeouts for all requests we send.
> But with the async client we are not able to get any exception, all requests are processed normally and all responses are obtained from the backend.
> 

The smallest granularity for I/O timeouts by default is 1 second. One
can reduce it by setting lower value of IOReactorConfig#selectInterval
at the cost of higher CPU utilization.

Oleg

> Checking the log:
> [exchange: 1] start execution
> [exchange: 1] Request connection for {}->http://10.20.30.246:80
> Connection request: [route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
> Connection leased: [id: http-outgoing-0][route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 2147483647; total allocated: 1 of 2147483647]
> [exchange: 1] Connection allocated: CPoolProxy{http-outgoing-0 [ACTIVE]}
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][r:]: Set attribute http.nio.exchange-handler
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Event set [w]
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1   <--- CONNECTION TIMEOUT?
> http-outgoing-0 [ACTIVE]: Connected
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set attribute http.nio.http-exchange-state
> Start connection routing
> Connection route established
> [exchange: 1] Attempt 1 to execute request
> Target auth state: UNCHALLENGED
> Proxy auth state: UNCHALLENGED
> http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1 <-- RESPONSE TIMEOUT?
> http-outgoing-0 >> POST /wsserhs/rhodasol HTTP/1.1
> http-outgoing-0 >> content-type: application/x-www-form-urlencoded; charset=ISO-8859-1
> http-outgoing-0 >> host: ws.rhodasol.es
> ( . . . )
> 
> It seems the values are correct, 1ms for both connection and response timeouts. Any response from the bakcend takes 100ms at least, because a Thread.sleep(100) is set before writing any byte to the servletoutputstream.
> 
> So, why are these exceptions not triggered?
> 
> Thanks,
> Joan.
> 
> 
> 
> 
> -----Mensaje original-----
> De: Oleg Kalnichevski [mailto:olegk@apache.org] 
> Enviado el: martes, 15 de marzo de 2016 16:14
> Para: HttpClient User Discussion
> Asunto: Re: Help with async client
> 
> On Tue, 2016-03-15 at 15:54 +0100, Joan Balagueró wrote:
> > Hello,
> > 
> >  
> > 
> > We have moved from the blocking client 
> > (PoolingHttpClientConnectionManager)
> > to the async one (PoolingNHttpClientConnectionManager), and we are 
> > starting some tests to check performance.
> > 
> >  
> > 
> > We have a test app that sends xml requests to our proxy. If the 
> > response is not found in cache,  the proxy uses the http client to get 
> > the responses from the back end.
> > 
> >  
> > 
> > Starting 20 threads, with the blocking client we reach about 700 
> > requests per second.
> > 
> >  
> > 
> > With the async client, the pattern we are seeing is: 20 requests are 
> > processed, then a 5 second pause, then 20 more requests processed, 5 
> > second pause, etc.
> > 
> >  
> > 
> > Obviously we have something misconfigured in our async pool. We though 
> > that the problem could come from the max htttp connections allowed, 
> > but checking the log:
> > 
> >  
> > 
> > [exchange: 2537] start execution
> > 
> > [exchange: 2537] Request connection for {}->http://10.20.30.246:80
> > 
> > Connection request: [route: {}->http://10.20.30.246:80][total kept 
> > alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 
> > 2147483647]
> > 
> > Connection leased: [id: http-outgoing-209][route:
> > {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 
> > 2147483647; total allocated: 1 of 2147483647]
> > 
> > [exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209 
> > [ACTIVE]}
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set 
> > attribute http.nio.exchange-handler
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Event set [w]
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set timeout 50000
> > 
> > http-outgoing-209 [ACTIVE]: Connected
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set attribute http.nio.http-exchange-state
> > 
> > Start connection routing
> > 
> > Connection route established
> > 
> > [exchange: 2537] Attempt 1 to execute request
> > 
> > Target auth state: UNCHALLENGED
> > 
> > Proxy auth state: UNCHALLENGED
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Set timeout 1000
> > 
> > http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1
> > 
> > http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
> > charset=ISO-8859-1
> > 
> > http-outgoing-209 >> host: ws.rhodasol.es
> > 
> > http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1 
> > (Java/1.7.0_75)
> > 
> > http-outgoing-209 >> x-ventusproxy-id:
> > bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbH
> > wyMDA4 
> > MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi
> > 5jb3Vu
> > dHJ5MzF8MjM
> > 
> > uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5ja
> > XR5fDI 
> > zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb
> > 25UeXB lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc
> > 
> > mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnw
> > yNC58M 
> > jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU
> > 5LTE=
> > 
> > http-outgoing-209 >> x-forwarded-for: 192.168.1.29
> > 
> > http-outgoing-209 >> Content-Length: 1368
> > 
> > http-outgoing-209 >> Connection: Keep-Alive
> > 
> > http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> > Event set [w]
> > 
> > http-outgoing-209 [ACTIVE] Output ready
> > 
> > [exchange: 2537] produce content
> > 
> > [exchange: 2537] Request completed
> > 
> >  
> > 
> > (etc).
> > 
> >  
> > 
> > I can send more information about this log and our pool configuration. 
> > But since the pattern is so clear, maybe someone has experienced 
> > something similar and can tell me what’s wrong.
> > 
> >  
> > 
> > I suppose that the following is not related with this issue, but we 
> > have and idleConnectionHandler that is executed every 5 seconds.
> > 
> >  
> > 
> > Thanks,
> > 
> >  
> > 
> > Joan.
> > 
> >  
> 
> Consider simplifying your application / configuration to something very basic, then start adding more complexity and see at which point the problem starts occurring.
> 
> You can take with this benchmark as a starting point 
> 
> http://svn.apache.org/repos/asf/httpcomponents/benchmark/httpclient/trunk/src/main/java/org/apache/http/client/benchmark/ApacheHttpAsyncClient.java
> 
> Oleg
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
> 
> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
> 



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

RE: Help with async client

Posted by Joan Balagueró <jo...@grupoventus.com>.
Hi Oleg,

Finally the issue was nothing to do with the async client.

Now we are experimenting with connection and response timeouts, setting just 1ms for both. In the blocking client, we get connection and response timeouts for all requests we send.
But with the async client we are not able to get any exception, all requests are processed normally and all responses are obtained from the backend.

Checking the log:
[exchange: 1] start execution
[exchange: 1] Request connection for {}->http://10.20.30.246:80
Connection request: [route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
Connection leased: [id: http-outgoing-0][route: {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 2147483647; total allocated: 1 of 2147483647]
[exchange: 1] Connection allocated: CPoolProxy{http-outgoing-0 [ACTIVE]}
http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][r:]: Set attribute http.nio.exchange-handler
http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Event set [w]
http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1   <--- CONNECTION TIMEOUT?
http-outgoing-0 [ACTIVE]: Connected
http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set attribute http.nio.http-exchange-state
Start connection routing
Connection route established
[exchange: 1] Attempt 1 to execute request
Target auth state: UNCHALLENGED
Proxy auth state: UNCHALLENGED
http-outgoing-0 10.20.30.70:53654<->10.20.30.246:80[ACTIVE][rw:]: Set timeout 1 <-- RESPONSE TIMEOUT?
http-outgoing-0 >> POST /wsserhs/rhodasol HTTP/1.1
http-outgoing-0 >> content-type: application/x-www-form-urlencoded; charset=ISO-8859-1
http-outgoing-0 >> host: ws.rhodasol.es
( . . . )

It seems the values are correct, 1ms for both connection and response timeouts. Any response from the bakcend takes 100ms at least, because a Thread.sleep(100) is set before writing any byte to the servletoutputstream.

So, why are these exceptions not triggered?

Thanks,
Joan.




-----Mensaje original-----
De: Oleg Kalnichevski [mailto:olegk@apache.org] 
Enviado el: martes, 15 de marzo de 2016 16:14
Para: HttpClient User Discussion
Asunto: Re: Help with async client

On Tue, 2016-03-15 at 15:54 +0100, Joan Balagueró wrote:
> Hello,
> 
>  
> 
> We have moved from the blocking client 
> (PoolingHttpClientConnectionManager)
> to the async one (PoolingNHttpClientConnectionManager), and we are 
> starting some tests to check performance.
> 
>  
> 
> We have a test app that sends xml requests to our proxy. If the 
> response is not found in cache,  the proxy uses the http client to get 
> the responses from the back end.
> 
>  
> 
> Starting 20 threads, with the blocking client we reach about 700 
> requests per second.
> 
>  
> 
> With the async client, the pattern we are seeing is: 20 requests are 
> processed, then a 5 second pause, then 20 more requests processed, 5 
> second pause, etc.
> 
>  
> 
> Obviously we have something misconfigured in our async pool. We though 
> that the problem could come from the max htttp connections allowed, 
> but checking the log:
> 
>  
> 
> [exchange: 2537] start execution
> 
> [exchange: 2537] Request connection for {}->http://10.20.30.246:80
> 
> Connection request: [route: {}->http://10.20.30.246:80][total kept 
> alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of 
> 2147483647]
> 
> Connection leased: [id: http-outgoing-209][route:
> {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of 
> 2147483647; total allocated: 1 of 2147483647]
> 
> [exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209 
> [ACTIVE]}
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set 
> attribute http.nio.exchange-handler
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> Event set [w]
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> Set timeout 50000
> 
> http-outgoing-209 [ACTIVE]: Connected
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> Set attribute http.nio.http-exchange-state
> 
> Start connection routing
> 
> Connection route established
> 
> [exchange: 2537] Attempt 1 to execute request
> 
> Target auth state: UNCHALLENGED
> 
> Proxy auth state: UNCHALLENGED
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> Set timeout 1000
> 
> http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1
> 
> http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
> charset=ISO-8859-1
> 
> http-outgoing-209 >> host: ws.rhodasol.es
> 
> http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1 
> (Java/1.7.0_75)
> 
> http-outgoing-209 >> x-ventusproxy-id:
> bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbH
> wyMDA4 
> MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi
> 5jb3Vu
> dHJ5MzF8MjM
> 
> uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5ja
> XR5fDI 
> zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb
> 25UeXB lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc
> 
> mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnw
> yNC58M 
> jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU
> 5LTE=
> 
> http-outgoing-209 >> x-forwarded-for: 192.168.1.29
> 
> http-outgoing-209 >> Content-Length: 1368
> 
> http-outgoing-209 >> Connection: Keep-Alive
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: 
> Event set [w]
> 
> http-outgoing-209 [ACTIVE] Output ready
> 
> [exchange: 2537] produce content
> 
> [exchange: 2537] Request completed
> 
>  
> 
> (etc).
> 
>  
> 
> I can send more information about this log and our pool configuration. 
> But since the pattern is so clear, maybe someone has experienced 
> something similar and can tell me what’s wrong.
> 
>  
> 
> I suppose that the following is not related with this issue, but we 
> have and idleConnectionHandler that is executed every 5 seconds.
> 
>  
> 
> Thanks,
> 
>  
> 
> Joan.
> 
>  

Consider simplifying your application / configuration to something very basic, then start adding more complexity and see at which point the problem starts occurring.

You can take with this benchmark as a starting point 

http://svn.apache.org/repos/asf/httpcomponents/benchmark/httpclient/trunk/src/main/java/org/apache/http/client/benchmark/ApacheHttpAsyncClient.java

Oleg


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




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

Re: Help with async client

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Tue, 2016-03-15 at 15:54 +0100, Joan Balagueró wrote:
> Hello,
> 
>  
> 
> We have moved from the blocking client (PoolingHttpClientConnectionManager)
> to the async one (PoolingNHttpClientConnectionManager), and we are starting
> some tests to check performance.
> 
>  
> 
> We have a test app that sends xml requests to our proxy. If the response is
> not found in cache,  the proxy uses the http client to get the responses
> from the back end. 
> 
>  
> 
> Starting 20 threads, with the blocking client we reach about 700 requests
> per second.
> 
>  
> 
> With the async client, the pattern we are seeing is: 20 requests are
> processed, then a 5 second pause, then 20 more requests processed, 5 second
> pause, etc.
> 
>  
> 
> Obviously we have something misconfigured in our async pool. We though that
> the problem could come from the max htttp connections allowed, but checking
> the log:
> 
>  
> 
> [exchange: 2537] start execution
> 
> [exchange: 2537] Request connection for {}->http://10.20.30.246:80
> 
> Connection request: [route: {}->http://10.20.30.246:80][total kept alive: 0;
> route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
> 
> Connection leased: [id: http-outgoing-209][route:
> {}->http://10.20.30.246:80][total kept alive: 0; route allocated: 1 of
> 2147483647; total allocated: 1 of 2147483647]
> 
> [exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209
> [ACTIVE]}
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set
> attribute http.nio.exchange-handler
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Event
> set [w]
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
> timeout 50000
> 
> http-outgoing-209 [ACTIVE]: Connected
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
> attribute http.nio.http-exchange-state
> 
> Start connection routing
> 
> Connection route established
> 
> [exchange: 2537] Attempt 1 to execute request
> 
> Target auth state: UNCHALLENGED
> 
> Proxy auth state: UNCHALLENGED
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Set
> timeout 1000
> 
> http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1
> 
> http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
> charset=ISO-8859-1
> 
> http-outgoing-209 >> host: ws.rhodasol.es
> 
> http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1 (Java/1.7.0_75)
> 
> http-outgoing-209 >> x-ventusproxy-id:
> bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbHwyMDA4
> MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi5jb3Vu
> dHJ5MzF8MjM
> 
> uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5jaXR5fDI
> zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb25UeXB
> lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc
> 
> mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnwyNC58M
> jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU5LTE=
> 
> http-outgoing-209 >> x-forwarded-for: 192.168.1.29
> 
> http-outgoing-209 >> Content-Length: 1368
> 
> http-outgoing-209 >> Connection: Keep-Alive
> 
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]: Event
> set [w]
> 
> http-outgoing-209 [ACTIVE] Output ready
> 
> [exchange: 2537] produce content
> 
> [exchange: 2537] Request completed
> 
>  
> 
> (etc).
> 
>  
> 
> I can send more information about this log and our pool configuration. But
> since the pattern is so clear, maybe someone has experienced something
> similar and can tell me what’s wrong.
> 
>  
> 
> I suppose that the following is not related with this issue, but we have and
> idleConnectionHandler that is executed every 5 seconds.
> 
>  
> 
> Thanks,
> 
>  
> 
> Joan.
> 
>  

Consider simplifying your application / configuration to something very
basic, then start adding more complexity and see at which point the
problem starts occurring.

You can take with this benchmark as a starting point 

http://svn.apache.org/repos/asf/httpcomponents/benchmark/httpclient/trunk/src/main/java/org/apache/http/client/benchmark/ApacheHttpAsyncClient.java

Oleg


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