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:[email protected]]
> 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: [email protected]
> For additional commands, e-mail: [email protected]
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
