[
https://issues.apache.org/jira/browse/HTTPCLIENT-2344?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17884788#comment-17884788
]
Ben Plotnick edited comment on HTTPCLIENT-2344 at 9/25/24 9:18 PM:
-------------------------------------------------------------------
Here's a repro: [https://github.com/bplotnick/httpclient-envoy/tree/main]
And the logs:
{code:java}
13:23:47.361 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
preparing request execution
13:23:47.367 [main] DEBUG org.apache.hc.client5.http.impl.classic.ProtocolExec
- ex-0000000001 target auth state: UNCHALLENGED
13:23:47.367 [main] DEBUG org.apache.hc.client5.http.impl.classic.ProtocolExec
- ex-0000000001 proxy auth state: UNCHALLENGED
13:23:47.368 [main] DEBUG org.apache.hc.client5.http.impl.classic.ConnectExec -
ex-0000000001 acquiring connection with route {}->http://localhost:10000
13:23:47.371 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
acquiring endpoint (3 MINUTES)
13:23:47.372 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 endpoint lease request (3 MINUTES) [route:
{}->http://localhost:10000][total available: 0; route allocated: 0 of 5; total
allocated: 0 of 25]
13:23:47.373 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 endpoint leased [route: {}->http://localhost:10000][total
available: 0; route allocated: 1 of 5; total allocated: 1 of 25]
13:23:47.378 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 acquired ep-0000000001
13:23:47.378 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
acquired endpoint ep-0000000001
13:23:47.378 [main] DEBUG org.apache.hc.client5.http.impl.classic.ConnectExec -
ex-0000000001 opening connection {}->http://localhost:10000
13:23:47.379 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
connecting endpoint (null)
13:23:47.379 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connecting endpoint to http://localhost:10000 (3 MINUTES)
13:23:47.380 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
localhost resolving remote address
13:23:47.381 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
localhost resolved to [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1]
13:23:47.381 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
http://localhost:10000 connecting null->localhost/127.0.0.1:10000 (3 MINUTES)
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
http-outgoing-0 http://localhost:10000 connected
/127.0.0.1:60743->localhost/127.0.0.1:10000
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection -
http-outgoing-0 set socket timeout to 3 MINUTES
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connected http-outgoing-0
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
endpoint connected
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.classic.MainClientExec - ex-0000000001
executing GET / HTTP/1.1
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestUpgrade -
Connection is upgradable: protocol version = HTTP/1.1
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestUpgrade -
Connection is upgradable to TLS: method = GET
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestAddCookies
- ex-0000000001 Cookie spec selected: strict
13:23:47.396 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
start execution ex-0000000001
13:23:47.396 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 executing exchange ex-0000000001 over http-outgoing-0
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> GET / HTTP/1.1
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Accept-Encoding: gzip, x-gzip, deflate
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Host: localhost:10000
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Connection: keep-alive
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> User-Agent: Apache-HttpClient/5.4 (Java/21.0.3)
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Upgrade: TLS/1.2
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Connection: Upgrade
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"GET / HTTP/1.1[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Accept-Encoding: gzip, x-gzip, deflate[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Host: localhost:10000[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Connection: keep-alive[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"User-Agent: Apache-HttpClient/5.4 (Java/21.0.3)[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Upgrade: TLS/1.2[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Connection: Upgrade[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"HTTP/1.1 403 Forbidden[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"date: Wed, 25 Sep 2024 17:23:47 GMT[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"server: envoy[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"connection: close[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"content-length: 0[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"[\r][\n]"
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< HTTP/1.1 403 Forbidden
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< date: Wed, 25 Sep 2024 17:23:47 GMT
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< server: envoy
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< connection: close
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< content-length: 0
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection -
http-outgoing-0 close connection IMMEDIATE
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
endpoint closed
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
discarding endpoint
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 releasing endpoint
13:23:47.416 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connection is not kept alive)
13:23:47.416 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connection released [route: {}->http://localhost:10000][total
available: 0; route allocated: 0 of 5; total allocated: 0 of 25]
Response code: 403
Response body:
13:23:47.417 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
Shutdown connection pool GRACEFUL
13:23:47.417 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
Connection pool shut down{code}
I tried a number of other proxies and they did not have this issue.
That being said, I still stand by my previous statement that adding this as a
default is not the right thing to do since Envoy/Istio is widely used in a
sidecar configuration with this exact scenario on millions of machines. This
does break real deployed applications and it's worth considering whether that
is the best thing to do for the users.
was (Author: JIRAUSER307140):
Here's a repro: [https://github.com/bplotnick/httpclient-envoy/tree/main]
And the logs:
```
13:23:47.361 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
preparing request execution
13:23:47.367 [main] DEBUG org.apache.hc.client5.http.impl.classic.ProtocolExec
- ex-0000000001 target auth state: UNCHALLENGED
13:23:47.367 [main] DEBUG org.apache.hc.client5.http.impl.classic.ProtocolExec
- ex-0000000001 proxy auth state: UNCHALLENGED
13:23:47.368 [main] DEBUG org.apache.hc.client5.http.impl.classic.ConnectExec -
ex-0000000001 acquiring connection with route {}->[http://localhost:10000]
13:23:47.371 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
acquiring endpoint (3 MINUTES)
13:23:47.372 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 endpoint lease request (3 MINUTES) [route:
{}->[http://localhost:10000]][total available: 0; route allocated: 0 of 5;
total allocated: 0 of 25]
13:23:47.373 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 endpoint leased [route: {}->[http://localhost:10000]][total
available: 0; route allocated: 1 of 5; total allocated: 1 of 25]
13:23:47.378 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ex-0000000001 acquired ep-0000000001
13:23:47.378 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-0000000001
acquired endpoint ep-0000000001
13:23:47.378 [main] DEBUG org.apache.hc.client5.http.impl.classic.ConnectExec -
ex-0000000001 opening connection {}->[http://localhost:10000]
13:23:47.379 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
connecting endpoint (null)
13:23:47.379 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connecting endpoint to http://localhost:10000 (3 MINUTES)
13:23:47.380 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
localhost resolving remote address
13:23:47.381 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
localhost resolved to [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1]
13:23:47.381 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
http://localhost:10000 connecting null->localhost/127.0.0.1:10000 (3 MINUTES)
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator -
http-outgoing-0 http://localhost:10000 connected
/127.0.0.1:60743->localhost/127.0.0.1:10000
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection -
http-outgoing-0 set socket timeout to 3 MINUTES
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connected http-outgoing-0
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
endpoint connected
13:23:47.393 [main] DEBUG
org.apache.hc.client5.http.impl.classic.MainClientExec - ex-0000000001
executing GET / HTTP/1.1
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestUpgrade -
Connection is upgradable: protocol version = HTTP/1.1
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestUpgrade -
Connection is upgradable to TLS: method = GET
13:23:47.393 [main] DEBUG org.apache.hc.client5.http.protocol.RequestAddCookies
- ex-0000000001 Cookie spec selected: strict
13:23:47.396 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
start execution ex-0000000001
13:23:47.396 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 executing exchange ex-0000000001 over http-outgoing-0
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> GET / HTTP/1.1
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Accept-Encoding: gzip, x-gzip, deflate
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Host: localhost:10000
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Connection: keep-alive
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> User-Agent: Apache-HttpClient/5.4 (Java/21.0.3)
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Upgrade: TLS/1.2
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
>> Connection: Upgrade
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"GET / HTTP/1.1[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Accept-Encoding: gzip, x-gzip, deflate[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Host: localhost:10000[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Connection: keep-alive[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"User-Agent: Apache-HttpClient/5.4 (Java/21.0.3)[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Upgrade: TLS/1.2[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"Connection: Upgrade[\r][\n]"
13:23:47.397 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 >>
"[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"HTTP/1.1 403 Forbidden[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"date: Wed, 25 Sep 2024 17:23:47 GMT[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"server: envoy[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"connection: close[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"content-length: 0[\r][\n]"
13:23:47.411 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 <<
"[\r][\n]"
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< HTTP/1.1 403 Forbidden
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< date: Wed, 25 Sep 2024 17:23:47 GMT
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< server: envoy
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< connection: close
13:23:47.412 [main] DEBUG org.apache.hc.client5.http.headers - http-outgoing-0
<< content-length: 0
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection -
http-outgoing-0 close connection IMMEDIATE
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
endpoint closed
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-0000000001
discarding endpoint
13:23:47.415 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 releasing endpoint
13:23:47.416 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connection is not kept alive)
13:23:47.416 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
ep-0000000001 connection released [route: {}->[http://localhost:10000]][total
available: 0; route allocated: 0 of 5; total allocated: 0 of 25]
Response code: 403
Response body:
13:23:47.417 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
Shutdown connection pool GRACEFUL
13:23:47.417 [main] DEBUG
org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager -
Connection pool shut down
```
I tried a number of other proxies and they did not have this issue.
That being said, I still stand by my previous statement that adding this as a
default is not the right thing to do since Envoy/Istio is widely used in a
sidecar configuration with this exact scenario on millions of machines. This
does break real deployed applications and it's worth considering whether that
is the best thing to do for the users.
> HTTP/1.1 TLS Upgrade (RFC-2817) should not be default
> -----------------------------------------------------
>
> Key: HTTPCLIENT-2344
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2344
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic)
> Affects Versions: 5.4
> Reporter: Ben Plotnick
> Priority: Minor
> Fix For: 5.4.1
>
>
> Version 5.4 added RFC-2817 support, which by default tries to upgrade since
> protocolUpgradeEnabled is default enabled.
> Although the strict reading of the spec would indicate that a server should
> ignore upgrade requests that it cannot service, conservative proxies might
> reject these requests entirely. This is the case in Envoy today
> I don't see a big advantage to enabling this by default and it is causing
> real issues now.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@hc.apache.org
For additional commands, e-mail: dev-h...@hc.apache.org
