On Tue, 2019-08-27 at 11:27 +0200, Joan grupoventus wrote: > 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. >
Could you please try to reproduce the issue inside a docker container? Oleg > -----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.InternalHttpAsyncClien > > t] > > 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.InternalHttpAsyncClien > > t] > > ex-00000001: acquiring endpoint (3 MINUTES) > > 2019-08-23 09:46:30,685 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > 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.PoolingAsyncClientConnec > > ti > > 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.PoolingAsyncClientConnec > > ti > > onManager] ex-00000001: acquired ep-00000000 > > 2019-08-23 09:46:30,690 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ex-00000001: acquired endpoint ep-00000000 > > 2019-08-23 09:46:30,691 DEBUG > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncClien > > t] > > ep-00000000: connecting endpoint (3 MINUTES) > > 2019-08-23 09:46:30,692 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > 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.MultihomeIOSessionReques > > te > > 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.MultihomeIOSessionReques > > te > > 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.MultihomeIOSessionReques > > te > > 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.DefaultManagedAsyncClientCon > > ne > > ction] i/o-00000000: start TLS > > 2019-08-23 09:46:30,963 DEBUG [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnection > > Ma > > 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.PoolingAsyncClientConnection > > Ma > > 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.DefaultManagedAsyncClientCon > > ne > > 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.PoolingAsyncClientConnection > > Ma > > nager] ep-00000000: close IMMEDIATE > > 2019-08-23 09:46:31,162 DEBUG [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientCon > > ne > > 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.PoolingAsyncClientConnection > > Ma > > nager] ep-00000000: releasing endpoint > > 2019-08-23 09:46:31,164 DEBUG [httpclient-dispatch- > > 1][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnection > > Ma > > 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(EngineInpu > > tR > > 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(SSLIOSessi > > on > > .java:313) > > at > > org.apache.hc.core5.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOS > > es > > sion.java:529) > > at > > org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalD > > at > > aChannel.java:122) > > at > > org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalC > > ha > > nnel.java:51) > > at > > org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(Singl > > eC > > oreIOReactor.java:177) > > at > > org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCor > > eI > > OReactor.java:127) > > at > > org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(Abs > > tr > > actSingleCoreIOReactor.java:82) > > at > > org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.jav > > a: > > 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.ja > > va > > :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(EngineInpu > > tR > > 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(SSLIOSessi > > on > > .java:313) > > at > > org.apache.hc.core5.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOS > > es > > sion.java:529) > > at > > org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalD > > at > > aChannel.java:122) > > at > > org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalC > > ha > > nnel.java:51) > > at > > org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(Singl > > eC > > oreIOReactor.java:177) > > at > > org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCor > > eI > > OReactor.java:127) > > at > > org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(Abs > > tr > > actSingleCoreIOReactor.java:82) > > at > > org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.jav > > a: > > 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.InternalHttpAsyncClien > > t] > > Shutdown GRACEFUL > > 2019-08-23 09:46:31,180 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > onManager] Shutdown connection pool GRACEFUL > > 2019-08-23 09:46:31,181 DEBUG > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnec > > ti > > 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.InternalHttpAsyncCli > > > en > > > 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.InternalHttpAsyncCli > > > en > > > t] > > > ex-00000001: acquiring endpoint (3 MINUTES) > > > 2019-08-22 12:02:43,995 DEBUG > > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConn > > > ec > > > 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.PoolingAsyncClientConn > > > ec > > > 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.PoolingAsyncClientConn > > > ec > > > ti > > > onManag > > > er] ex-00000001: acquired ep-00000000 > > > 2019-08-22 12:02:43,999 DEBUG > > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncCli > > > en > > > t] > > > ex-00000001: acquired endpoint ep-00000000 > > > 2019-08-22 12:02:43,999 DEBUG > > > [main][org.apache.hc.client5.http.impl.async.InternalHttpAsyncCli > > > en > > > t] > > > ep-00000000: connecting endpoint (3 MINUTES) > > > 2019-08-22 12:02:44,000 DEBUG > > > [main][org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConn > > > ec > > > 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.MultihomeIOSessionRequ > > > es > > > te > > > r] > > > https://localhost:8080: resolving remote address > > > 2019-08-22 12:02:44,001 DEBUG > > > [main][org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequ > > > es > > > 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.MultihomeIOSessionRequ > > > es > > > 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 > --------------------------------------------------------------------- To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org For additional commands, e-mail: httpclient-users-h...@hc.apache.org