Mailing-List: contact httpclient-users-help@hc.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "HttpClient User Discussion" <httpclient-users@hc.apache.org>
From: =?utf-8?Q?Joan_Balaguer=C3=B3?= <joan.balaguero@grupoventus.com>
To: "'HttpClient User Discussion'" <httpclient-users@hc.apache.org>
References: <003601d17eca$9422b090$bc6811b0$@grupoventus.com>
 <1458054811.3465.9.camel@apache.org>
In-Reply-To: <1458054811.3465.9.camel@apache.org>
Subject: RE: Help with async client
Date: Wed, 16 Mar 2016 15:41:55 +0100
Message-ID: <008f01d17f91$fcbd87c0$f6389740$@grupoventus.com>
MIME-Version: 1.0
Content-Type: text/plain;
	charset="utf-8"
Content-Transfer-Encoding: quoted-printable
Thread-Index: AQHs0RBO945ekkbQLet8xpGZcKTFLQJk+OApnxJXmRA=
Content-Language: es

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=3DISO-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]=20
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=C3=B3 wrote:
> Hello,
>=20
> =20
>=20
> We have moved from the blocking client=20
> (PoolingHttpClientConnectionManager)
> to the async one (PoolingNHttpClientConnectionManager), and we are=20
> starting some tests to check performance.
>=20
> =20
>=20
> We have a test app that sends xml requests to our proxy. If the=20
> response is not found in cache,  the proxy uses the http client to get =

> the responses from the back end.
>=20
> =20
>=20
> Starting 20 threads, with the blocking client we reach about 700=20
> requests per second.
>=20
> =20
>=20
> With the async client, the pattern we are seeing is: 20 requests are=20
> processed, then a 5 second pause, then 20 more requests processed, 5=20
> second pause, etc.
>=20
> =20
>=20
> Obviously we have something misconfigured in our async pool. We though =

> that the problem could come from the max htttp connections allowed,=20
> but checking the log:
>=20
> =20
>=20
> [exchange: 2537] start execution
>=20
> [exchange: 2537] Request connection for {}->http://10.20.30.246:80
>=20
> Connection request: [route: {}->http://10.20.30.246:80][total kept=20
> alive: 0; route allocated: 0 of 2147483647; total allocated: 0 of=20
> 2147483647]
>=20
> 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]
>=20
> [exchange: 2537] Connection allocated: CPoolProxy{http-outgoing-209=20
> [ACTIVE]}
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][r:]: Set =

> attribute http.nio.exchange-handler
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]:=20
> Event set [w]
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]:=20
> Set timeout 50000
>=20
> http-outgoing-209 [ACTIVE]: Connected
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]:=20
> Set attribute http.nio.http-exchange-state
>=20
> Start connection routing
>=20
> Connection route established
>=20
> [exchange: 2537] Attempt 1 to execute request
>=20
> Target auth state: UNCHALLENGED
>=20
> Proxy auth state: UNCHALLENGED
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]:=20
> Set timeout 1000
>=20
> http-outgoing-209 >> POST /wsserhs/rhodasol HTTP/1.1
>=20
> http-outgoing-209 >> content-type: application/x-www-form-urlencoded;
> charset=3DISO-8859-1
>=20
> http-outgoing-209 >> host: ws.rhodasol.es
>=20
> http-outgoing-209 >> user-agent: Apache-HttpClient/4.4.1=20
> (Java/1.7.0_75)
>=20
> http-outgoing-209 >> x-ventusproxy-id:
> bnVsbHxudWxsfG51bGx8bnVsbHxudWxsfG51bGx8QlI2MzczfFRFU1RNQ3xGUkF8bnVsbH
> wyMDA4=20
> MDYwMnxudWxsfG51bGx8MTguMnwxOS4yfDIwLjF8MTguM3wxOS48bnVsbD58MjAuMnwyMi
> 5jb3Vu
> dHJ5MzF8MjM
>=20
> uMHwyNC5FU1B8MjIuYXJlYXwyMy4wfDI0LjExfDIyLnJlZ2lvbnwyMy4wfDI0LnwyMi5ja
> XR5fDI=20
> zLjB8MjQufDIyLmFjY29tbW9kYXRpb25Db2RlfDIzLjF8MjQufDIyLmFjY29tbW9kYXRpb
> 25UeXB lfDIzLjF8MjQuMHwyMi5jYXRlZ29yeXwyMy4xfDI0LnwyMi5wc
>=20
> mljZVR5cGV8MjMuMnwyNC4zfDIyLm9mZmVyfDIzLjJ8MjQufDIyLmNvbmNlcHR8MjMuMnw
> yNC58M=20
> jIuYm9hcmR8MjMuMnwyNC58MjIuY2FuY2VsUG9saWNpZXN8MjMuMnwyNC4xfGlzby04ODU
> 5LTE=3D
>=20
> http-outgoing-209 >> x-forwarded-for: 192.168.1.29
>=20
> http-outgoing-209 >> Content-Length: 1368
>=20
> http-outgoing-209 >> Connection: Keep-Alive
>=20
> http-outgoing-209 10.20.30.70:57638<->10.20.30.246:80[ACTIVE][rw:]:=20
> Event set [w]
>=20
> http-outgoing-209 [ACTIVE] Output ready
>=20
> [exchange: 2537] produce content
>=20
> [exchange: 2537] Request completed
>=20
> =20
>=20
> (etc).
>=20
> =20
>=20
> I can send more information about this log and our pool configuration. =

> But since the pattern is so clear, maybe someone has experienced=20
> something similar and can tell me what=E2=80=99s wrong.
>=20
> =20
>=20
> I suppose that the following is not related with this issue, but we=20
> have and idleConnectionHandler that is executed every 5 seconds.
>=20
> =20
>=20
> Thanks,
>=20
> =20
>=20
> Joan.
>=20
> =20

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

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

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