Hello,
�
A mistake made by one of our clients has brought us a possible issue to our
attention. We have been able to reproduce it on our test environment.
�
The client has an endpoint that only listens on http connections on ports
8080,8081,8082 and 8083. By mistake all traffic from our gateway to their
backend has been sent by https instead of http, and this provoked the pool to
have all connections allocated (pool exhausted).
�
We have tried to send https requests to an http endpoint using post methods
through a “
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg>
org.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache>
apache.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc>
hc.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5>
client5.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http>
http.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http.impl>
impl.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http.impl.io>
io.PoolingHttpClientConnectionManager”. Just send the request synchronously
and await the response … and the error we immediately get is:
javax.net.ssl.SSLException: Unrecognized SSL message, plaintext connection?
�
That’s ok. Now we have tried the real situation, sending a request
asynchronously to the same endpoint using a “
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg>
org.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache>
apache.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc>
hc.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5>
client5.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http>
http.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http.impl>
impl.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpclient5-5.0-beta5.jar%3Corg.apache.hc.client5.http.impl.nio>
nio.PoolingAsyncClientConnectionManager” and trying to manage the response in
a “
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg>
org.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg.apache>
apache.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg.apache.hc>
hc.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg.apache.hc.core5>
core5.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg.apache.hc.core5.http>
http.
<eclipse-javadoc:%E2%98%82=vpfw/web%5C/WEB-INF%5C/lib%5C/httpcore5-5.0-beta8.jar%3Corg.apache.hc.core5.http.nio>
nio.AsyncResponseConsumer”. The result is the request never finishes (the
thread is only released when the container asynchronous timeout is reached) and
the connection is never returned to the pool.
�
This is the trace for the first request sent at 20:30:51 that finished after
120s when the container asynchronous timeout was reached:
�
App trace:
20:30:51.379,120419,response.noResponse,20:32:51.798
�
Http5 trace:
20:30:51.381 � � � ex-00000004: preparing request execution
20:30:51.381 � � � ex-00000004: target auth state: UNCHALLENGED
20:30:51.381 � � � ex-00000004: proxy auth state: UNCHALLENGED
20:30:51.381 � � � ex-00000004: acquiring connection with route
{s}->https://54.38.179.182:8080
20:30:51.381 � � � ex-00000004: acquiring endpoint (1 MILLISECONDS)
20:30:51.382 � � � ex-00000004: endpoint lease request (1 MILLISECONDS) [route:
{s}->https://54.38.179.182:8080][total kept alive: 0; route allocated: 0 of 50;
total allocated: 0 of 50]
20:30:51.382 � � � ex-00000004: endpoint leased [route:
{s}->https://54.38.179.182:8080][total kept alive: 0; route allocated: 1 of 50;
total allocated: 1 of 50]
20:30:51.382 � � � ex-00000004: acquired ep-00000003
20:30:51.382 � � � ex-00000004: acquired endpoint ep-00000003
20:30:51.382 � � � ep-00000003: connecting endpoint (2,000 MILLISECONDS)
20:30:51.382 � � � ep-00000003: connecting endpoint to
https://54.38.179.182:8080 (2,000 MILLISECONDS)
20:30:51.382 � � � https://54.38.179.182:8080: resolving remote address
20:30:51.382 � � � https://54.38.179.182:8080: resolved to [/54.38.179.182]
20:30:51.382 � � � https://54.38.179.182:8080: connecting null to
/54.38.179.182:8080 (2,000 MILLISECONDS)
20:30:51.383 � � � https://54.38.179.182:8080: connected i/o-00000003
/54.36.51.138:45374->/54.38.179.182:8080
20:30:51.383 � � � i/o-00000003: start TLS
20:30:51.383 � � � ep-00000003: connected i/o-00000003
20:30:51.383 � � � ep-00000003: endpoint connected
20:30:51.383 � � � ex-00000004: connected to target
20:30:51.383 � � � ex-00000004: route fully established
20:30:51.383 � � � ex-00000004: executing POST /serhs HTTP/1.1
20:30:51.383 � � � ep-00000003: start execution ex-00000004
20:30:51.383 � � � ep-00000003: executing exchange ex-00000004 over i/o-00000003
20:30:51.383 � � � i/o-00000003: RequestExecutionCommand with NORMAL priority
20:30:51.383 � � � Enabled protocols: [TLSv1.2]
20:30:51.383 � � � Enabled cipher
suites:[TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,
TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,
TLS_DHE_DSS_WITH_AES_128_GCM_SHA256]
�
�
And this is the trace for the second request sent at 20:30:51. A second
connection is allocated:
�
App trace:
20:33:11.636,120173,response.noResponse,20:35:11.809
�
Http5 trace:
20:33:11.638 � � � ex-00000005: preparing request execution
20:33:11.638 � � � ex-00000005: target auth state: UNCHALLENGED
20:33:11.638 � � � ex-00000005: proxy auth state: UNCHALLENGED
20:33:11.638 � � � ex-00000005: acquiring connection with route
{s}->https://54.38.179.182:8081
20:33:11.638 � � � ex-00000005: acquiring endpoint (1 MILLISECONDS)
20:33:11.638 � � � ex-00000005: endpoint lease request (1 MILLISECONDS) [route:
{s}->https://54.38.179.182:8081][total kept alive: 0; route allocated: 0 of 50;
total allocated: 1 of 50]
20:33:11.638 � � � ex-00000005: endpoint leased [route:
{s}->https://54.38.179.182:8081][total kept alive: 0; route allocated: 1 of 50;
total allocated: 2 of 50]
20:33:11.638 � � � ex-00000005: acquired ep-00000004
20:33:11.639 � � � ex-00000005: acquired endpoint ep-00000004
20:33:11.639 � � � ep-00000004: connecting endpoint (2,000 MILLISECONDS)
20:33:11.639 � � � ep-00000004: connecting endpoint to
https://54.38.179.182:8081 (2,000 MILLISECONDS)
20:33:11.639 � � � https://54.38.179.182:8081: resolving remote address
20:33:11.639 � � � https://54.38.179.182:8081: resolved to [/54.38.179.182]
20:33:11.639 � � � https://54.38.179.182:8081: connecting null to
/54.38.179.182:8081 (2,000 MILLISECONDS)
20:33:11.640 � � � https://54.38.179.182:8081: connected i/o-00000004
/54.36.51.138:36134->/54.38.179.182:8081
20:33:11.640 � � � i/o-00000004: start TLS
20:33:11.640 � � � ep-00000004: connected i/o-00000004
20:33:11.640 � � � ep-00000004: endpoint connected
20:33:11.640 � � � ex-00000005: connected to target
20:33:11.640 � � � ex-00000005: route fully established
20:33:11.640 � � � ex-00000005: executing POST /serhs HTTP/1.1
20:33:11.640 � � � ep-00000004: start execution ex-00000005
20:33:11.640 � � � ep-00000004: executing exchange ex-00000005 over i/o-00000004
20:33:11.640 � � � i/o-00000004: RequestExecutionCommand with NORMAL priority
20:33:11.640 � � � Enabled protocols: [TLSv1.2]
20:33:11.640 � � � Enabled cipher
suites:[TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,
TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,
TLS_DHE_DSS_WITH_AES_128_GCM_SHA256]
�
This is httpclient5-5.0-beta5 and httpcore5-5.0-beta8. The connection and
response timeout for these requests are 2s and 10s.
�
Let me know if you need further information.
�
Thanks,
Joan.
