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 whats 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.
