Hi Oleg, I uploaded the httpcore-5b9 we generated to the git. Is it possible you download it and try just one test with async Http5 to check if it works for you? We have checked the jar and it seems to be correct, so if you are using the same version I don't understand why it works for you and not for us.
Thanks, Joan. -----Original Message----- From: Oleg Kalnichevski <ol...@apache.org> Sent: Friday, August 23, 2019 5:32 PM To: HttpClient User Discussion <httpclient-users@hc.apache.org> Subject: Re: Issue sending https to an http endpoint On Fri, 2019-08-23 at 17:24 +0200, Joan grupoventus wrote: > Hi Oleg, > > Is this the right link to build the httpcore-b9? > https://github.com/apache/httpcomponents-core > Yes, it is. Oleg > We checked the version of our jar and it seems to be correctly. Is > there something else we have to build? We are already using the latest > httpclient (httpclient5-5.0-beta5) > > Thanks, > Joan. > > -----Original Message----- > From: Oleg Kalnichevski <ol...@apache.org> > Sent: Friday, August 23, 2019 9:49 AM > To: HttpClient User Discussion <httpclient-users@hc.apache.org> > Subject: Re: Issue sending https to an http endpoint > > On Thu, 2019-08-22 at 23:12 +0200, Joan grupoventus wrote: > > Hi Oleg, > > > > Well, not sure what's happening. In "our" git > > (https://github.com/joanbalaguero/HttpClient) I have uploaded 4 > > files that connect by https to the problematic url. > > > > The "TestSync" is using a sync http5 client and works, ends with an > > exception "javax.net.ssl.SSLException: Unrecognized SSL message, > > plaintext connection?" > > The " TestAsync41ResponseConsumer.java" is using the async http > > 4.1.3 > > client with an "HttpAsyncResponseConsumer" and works, ends with an > > exception > > "javax.net.ssl.SSLException: Unrecognized SSL message, plaintext > > connection?" > > > > The "TestAsync5FutureCallback" and "TestAsync5ResponseConsumer" > > are > > using an async http5 client (httpclient5-5-beta5 and > > httpcore5-5-beta9), the first one with a > > "FutureCallback<SimpleHttpResponse>" and the second with a > > "AsyncResponseConsumer<Void>". Both hang forever. > > > > So if this is not a bug in http5, what's wrong with these two last > > samples? > > The code there is minimal. > > > > Joan, > > I see nothing wrong with those samples and they all work for me > (HttpClient 5.0b5 + HttpCore 5.0b9-SNAPSHOT). > > Oleg > --- > 2019-08-23 09:46:30,669 DEBUG > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] > ex-00000001: preparing request execution > 2019-08-23 09:46:30,676 DEBUG > [main][org.apache.hc.client5.http.protocol.RequestAddCookies] > CookieSpec selected: standard > 2019-08-23 09:46:30,680 DEBUG > [main][org.apache.hc.client5.http.protocol.RequestAuthCache] Auth > cache not set in the context > 2019-08-23 09:46:30,680 DEBUG > [main][org.apache.hc.client5.http.impl.async.AsyncProtocolExec] ex- > 00000001: target auth state: UNCHALLENGED > 2019-08-23 09:46:30,681 DEBUG > [main][org.apache.hc.client5.http.impl.async.AsyncProtocolExec] ex- > 00000001: proxy auth state: UNCHALLENGED > 2019-08-23 09:46:30,683 DEBUG > [main][org.apache.hc.client5.http.impl.async.AsyncConnectExec] ex- > 00000001: acquiring connection with route {s}-> > https://54.38.179.182:8083 > 2019-08-23 09:46:30,684 DEBUG > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] > ex-00000001: acquiring endpoint (3 MINUTES) > 2019-08-23 09:46:30,685 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] ex-00000001: endpoint lease request (3 MINUTES) [route: > {s}->https://54.38.179.182:8083][total kept alive: 0; route > allocated: 0 of 5; total allocated: 0 of 25] > 2019-08-23 09:46:30,689 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] ex-00000001: endpoint leased [route: {s}-> > https://54.38.179.182:8083][total kept alive: 0; route allocated: 1 of > 5; total allocated: 1 of 25] > 2019-08-23 09:46:30,690 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] ex-00000001: acquired ep-00000000 > 2019-08-23 09:46:30,690 DEBUG > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] > ex-00000001: acquired endpoint ep-00000000 > 2019-08-23 09:46:30,691 DEBUG > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] > ep-00000000: connecting endpoint (3 MINUTES) > 2019-08-23 09:46:30,692 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] ep-00000000: connecting endpoint to > https://54.38.179.182:8083 (3 MINUTES) > 2019-08-23 09:46:30,692 DEBUG > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequeste > r] https://54.38.179.182:8083: resolving remote address > 2019-08-23 09:46:30,692 DEBUG > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequeste > r] https://54.38.179.182:8083: resolved to [/54.38.179.182] > 2019-08-23 09:46:30,693 DEBUG > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequeste > r] https://54.38.179.182:8083: connecting null to /54.38.179.182:8083 > (3 MINUTES) > 2019-08-23 09:46:30,907 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester] > https://54.38.179.182:8083: connected i/o-00000000 > /192.168.43.142:48810->/54.38.179.182:8083 > 2019-08-23 09:46:30,912 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConne > ction] i/o-00000000: start TLS > 2019-08-23 09:46:30,963 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionMa > nager] ep-00000000: connected i/o-00000000 > 2019-08-23 09:46:30,964 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] ep- > 00000000: endpoint connected > 2019-08-23 09:46:30,964 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.AsyncConnectExec] ex- > 00000001: connected to target > 2019-08-23 09:46:30,964 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.AsyncConnectExec] ex- > 00000001: route fully established > 2019-08-23 09:46:30,966 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec] ex- > 00000001: executing POST /serhs HTTP/1.1 > 2019-08-23 09:46:30,969 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] ep- > 00000000: start execution ex-00000001 > 2019-08-23 09:46:30,969 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionMa > nager] ep-00000000: executing exchange ex-00000001 over i/o-00000000 > 2019-08-23 09:46:30,970 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConne > ction] i/o-00000000: RequestExecutionCommand with NORMAL priority > 2019-08-23 09:46:30,977 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.ssl.DefaultClientTlsStrategy] Enabled > protocols: [TLSv1.2] > 2019-08-23 09:46:30,977 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.ssl.DefaultClientTlsStrategy] 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] > 2019-08-23 09:46:31,161 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec] ex- > 00000001: execution failed: Unrecognized SSL message, plaintext > connection? > 2019-08-23 09:46:31,162 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] ex- > 00000001: request failed: Unrecognized SSL message, plaintext > connection? > 2019-08-23 09:46:31,162 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionMa > nager] ep-00000000: close IMMEDIATE > 2019-08-23 09:46:31,162 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConne > ction] i/o-00000000: Shutdown connection IMMEDIATE > 2019-08-23 09:46:31,163 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] ep- > 00000000: endpoint closed > 2019-08-23 09:46:31,163 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] ep- > 00000000: discarding endpoint > 2019-08-23 09:46:31,163 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionMa > nager] ep-00000000: releasing endpoint > 2019-08-23 09:46:31,164 DEBUG [httpclient-dispatch- > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionMa > nager] ep-00000000: connection released [route: {s}-> > https://54.38.179.182:8083][total kept alive: 0; route allocated: 0 of > 5; total allocated: 0 of 25] failed > !!!!javax.net.ssl.SSLException: Unrecognized SSL message, plaintext > connection? > at > sun.security.ssl.EngineInputRecord.bytesInCompletePacket(EngineInputR > ecord.java:156) > at > sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:868) > at > sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) > at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.doUnwrap(SSLIOSession.ja > va:267) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.doHandshake(SSLIOSession > .java:313) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOSes > sion.java:529) > at > org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalDat > aChannel.java:122) > at > org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalCha > nnel.java:51) > at > org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(SingleC > oreIOReactor.java:177) > at > org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreI > OReactor.java:127) > at > org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(Abstr > actSingleCoreIOReactor.java:82) > at > org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java: > 44) > at java.lang.Thread.run(Thread.java:748) > java.util.concurrent.ExecutionException: javax.net.ssl.SSLException: > Unrecognized SSL message, plaintext connection? > at > org.apache.hc.core5.concurrent.BasicFuture.getResult(BasicFuture.java > :72) > at > org.apache.hc.core5.concurrent.BasicFuture.get(BasicFuture.java:85) > at > testing.TestAsync5FutureCallback.main(TestAsync5FutureCallback.java:4 > 5) > Caused by: javax.net.ssl.SSLException: Unrecognized SSL message, > plaintext connection? > at > sun.security.ssl.EngineInputRecord.bytesInCompletePacket(EngineInputR > ecord.java:156) > at > sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:868) > at > sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) > at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.doUnwrap(SSLIOSession.ja > va:267) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.doHandshake(SSLIOSession > .java:313) > at > org.apache.hc.core5.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOSes > sion.java:529) > at > org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalDat > aChannel.java:122) > at > org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalCha > nnel.java:51) > at > org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(SingleC > oreIOReactor.java:177) > at > org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreI > OReactor.java:127) > at > org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(Abstr > actSingleCoreIOReactor.java:82) > at > org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java: > 44) > at java.lang.Thread.run(Thread.java:748) > 2019-08-23 09:46:31,169 DEBUG > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient] > Shutdown GRACEFUL > 2019-08-23 09:46:31,180 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] Shutdown connection pool GRACEFUL > 2019-08-23 09:46:31,181 DEBUG > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnecti > onManager] Connection pool shut down > > > > Thanks, > > Joan. > > > > > > -----Original Message----- > > From: Oleg Kalnichevski <ol...@apache.org> > > Sent: Thursday, August 22, 2019 12:05 PM > > To: HttpClient User Discussion <httpclient-users@hc.apache.org> > > Subject: Re: Issue sending https to an http endpoint > > > > On Wed, 2019-08-21 at 22:24 +0200, Joan grupoventus wrote: > > > Hi Oleg, > > > > > > Tried with httpcore5-5.0-beta9.jar. The same result. > > > > > > > I am sorry, Joan, but I am unable to reproduce the problem with > > HttpClient > > 5.0-beta5 and the latest HttpCore 5.0-beta9-SNAPSHOT. It works as > > expected for me. > > > > Oleg > > > > --- > > 2019-08-22 12:02:43,978 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ex-00000001: preparing request execution > > 2019-08-22 12:02:43,986 DEBUG > > [main][org.apache.hc.client5.http.protocol.RequestAddCookies] > > CookieSpec > > selected: standard > > 2019-08-22 12:02:43,990 DEBUG > > [main][org.apache.hc.client5.http.protocol.RequestAuthCache] Auth > > cache not set in the context > > 2019-08-22 12:02:43,991 DEBUG > > [main][org.apache.hc.client5.http.impl.async.AsyncProtocolExec] ex- > > 00000001: > > target auth state: UNCHALLENGED > > 2019-08-22 12:02:43,991 DEBUG > > [main][org.apache.hc.client5.http.impl.async.AsyncProtocolExec] ex- > > 00000001: > > proxy auth state: UNCHALLENGED > > 2019-08-22 12:02:43,993 DEBUG > > [main][org.apache.hc.client5.http.impl.async.AsyncConnectExec] ex- > > 00000001: > > acquiring connection with route {s}->https://localhost:8080 > > 2019-08-22 12:02:43,993 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ex-00000001: acquiring endpoint (3 MINUTES) > > 2019-08-22 12:02:43,995 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > onManag > > er] ex-00000001: endpoint lease request (3 MINUTES) [route: > > {s}->https://localhost:8080][total kept alive: 0; route allocated: > > 0 > > of 5; total allocated: 0 of 25] > > 2019-08-22 12:02:43,998 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > onManag > > er] ex-00000001: endpoint leased [route: {s}-> > > https://localhost:8080][total kept alive: 0; route allocated: 1 of > > 5; total allocated: 1 of 25] > > 2019-08-22 12:02:43,998 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > onManag > > er] ex-00000001: acquired ep-00000000 > > 2019-08-22 12:02:43,999 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ex-00000001: acquired endpoint ep-00000000 > > 2019-08-22 12:02:43,999 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ep-00000000: connecting endpoint (3 MINUTES) > > 2019-08-22 12:02:44,000 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > onManag > > er] ep-00000000: connecting endpoint to https://localhost:8080 (3 > > MINUTES) > > 2019-08-22 12:02:44,000 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionReques > > te > > r] > > https://localhost:8080: resolving remote address > > 2019-08-22 12:02:44,001 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionReques > > te > > r] > > https://localhost:8080: resolved to [localhost/127.0.0.1] > > 2019-08-22 12:02:44,001 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionReques > > te > > r] > > https://localhost:8080: connecting null to localhost/127.0.0.1:8080 > > (3 > > MINUTES) > > 2019-08-22 12:02:44,023 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.MultihomeIOSessi > > onRequester] https://localhost:8080: connected i/o-00000000 > > /127.0.0.1:50902->localhost/127.0.0.1:8080 > > 2019-08-22 12:02:44,025 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAs > > yncClientConnection] i/o-00000000: start TLS > > 2019-08-22 12:02:44,042 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClie > > ntConnectionManager] ep-00000000: connected i/o-00000000 > > 2019-08-22 12:02:44,042 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.InternalHttpAs > > yncClient] ep-00000000: endpoint connected > > 2019-08-22 12:02:44,043 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.AsyncConnectEx > > ec] ex-00000001: connected to target > > 2019-08-22 12:02:44,043 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.AsyncConnectEx > > ec] ex-00000001: route fully established > > 2019-08-22 12:02:44,043 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.HttpAsyncMainC > > lientExec] ex-00000001: executing OPTIONS * HTTP/1.1 > > 2019-08-22 12:02:44,044 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.InternalHttpAs > > yncClient] ep-00000000: start execution ex-00000001 > > 2019-08-22 12:02:44,044 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClie > > ntConnectionManager] ep-00000000: executing exchange ex-00000001 > > over > > i/o-00000000 > > 2019-08-22 12:02:44,045 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAs > > yncClientConnection] i/o-00000000: RequestExecutionCommand with > > NORMAL priority > > 2019-08-22 12:02:44,047 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.ssl.DefaultClientTlsStrat > > egy] Enabled protocols: [TLSv1, TLSv1.1, TLSv1.2] > > 2019-08-22 12:02:44,047 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.ssl.DefaultClientTlsStrat > > egy] Enabled cipher > > suites:[TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, > > TLS_RSA_WITH_AES_256_CBC_SHA256, > > TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, > > TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, > > TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, > > TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, > > TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, > > TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, > > TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, > > TLS_DHE_RSA_WITH_AES_256_CBC_SHA, > > TLS_DHE_DSS_WITH_AES_256_CBC_SHA, > > TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, > > TLS_RSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, > > TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, > > TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, > > TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, > > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, > > TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, > > TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, > > TLS_DHE_RSA_WITH_AES_128_CBC_SHA, > > TLS_DHE_DSS_WITH_AES_128_CBC_SHA, > > 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_RSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDH_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_RSA_WITH_AES_128_GCM_SHA256, > > TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, > > TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, > > TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, > > TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, > > TLS_EMPTY_RENEGOTIATION_INFO_SCSV] > > 2019-08-22 12:02:44,083 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.HttpAsyncMainC > > lientExec] ex-00000001: execution failed: Unrecognized SSL message, > > plaintext connection? > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.InternalHttpAs > > yncClient] ex-00000001: request failed: Unrecognized SSL message, > > plaintext connection? > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClie > > ntConnectionManager] ep-00000000: close IMMEDIATE > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAs > > yncClientConnection] i/o-00000000: Shutdown connection IMMEDIATE > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.InternalHttpAs > > yncClient] ep-00000000: endpoint closed > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.async.InternalHttpAs > > yncClient] ep-00000000: discarding endpoint > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClie > > ntConnectionManager] ep-00000000: releasing endpoint > > 2019-08-22 12:02:44,084 DEBUG > > [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClie > > ntConnectionManager] ep-00000000: connection released [route: > > {s}->https://localhost:8080][total kept alive: 0; route allocated: > > 0 > > of 5; total allocated: 0 of 25] > > NOK: HTTP/1.1 https://localhost:8080: OPTIONS * -> (Unrecognized SSL > > message, plaintext connection?) > > > > > 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.PoolingHttpClientConnectionManag"r”. Just send the request > > > > synchronously and await the respo...se … 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.PoolingAsyncClientConnectionManag"r” and trying to manage > > > > the response i" 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.AsyncResponseCo"sumer”. > > > > 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 > > > > > > > > > ----------------------------------------------------------------- > > ---- > > 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 > > > --------------------------------------------------------------------- > 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 > --------------------------------------------------------------------- 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
