Hi Oleg, Tried with httpcore5-5.0-beta9.jar. The same result.
Thanks, Joan. -----Original Message----- From: Oleg Kalnichevski <ol...@apache.org> Sent: Monday, August 19, 2019 9:15 AM To: HttpClient User Discussion <httpclient-users@hc.apache.org> Subject: Re: Issue sending https to an http endpoint On Sun, 2019-08-18 at 21:05 +0200, Joan grupoventus wrote: > 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). > Hi Joan I think this issue has already been resolved in HttpCore master. Could you please try to reproduce the issue the latest HttpCore snapshot? You will need to build HttpCore from source to do so. https://github.com/apache/httpcomponents-core Oleg > > > 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. > --------------------------------------------------------------------- To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org For additional commands, e-mail: httpclient-users-h...@hc.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org For additional commands, e-mail: httpclient-users-h...@hc.apache.org
