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 <[email protected]> > Sent: Friday, August 23, 2019 9:49 AM > To: HttpClient User Discussion <[email protected]> > 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 <[email protected]> > > Sent: Thursday, August 22, 2019 12:05 PM > > To: HttpClient User Discussion <[email protected]> > > 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 <[email protected]> > > > Sent: Monday, August 19, 2019 9:15 AM > > > To: HttpClient User Discussion <[email protected]> > > > 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: > > > [email protected] > > > For additional commands, e-mail: > > > [email protected] > > > > > > > > > > > > > > > ----------------------------------------------------------------- > > > ---- > > > To unsubscribe, e-mail: > > > [email protected] > > > For additional commands, e-mail: > > > [email protected] > > > > > > > > > ----------------------------------------------------------------- > > ---- > > To unsubscribe, e-mail: [email protected] > > For additional commands, e-mail: > > [email protected] > > > > > > > > ----------------------------------------------------------------- > > ---- > > To unsubscribe, e-mail: [email protected] > > For additional commands, e-mail: > > [email protected] > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
