[
https://issues.apache.org/jira/browse/HTTPCLIENT-2118?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17206319#comment-17206319
]
Michael Osipov commented on HTTPCLIENT-2118:
--------------------------------------------
This is truly fishy, now we have:
{noformat}
2020-10-02 16:48:32.096 DEBUG [main] o.a.h.c.http.impl.classic.ProtocolExec :
ex-00000006: target auth state: UNCHALLENGED
2020-10-02 16:48:32.096 DEBUG [main] o.a.h.c.http.impl.classic.ProtocolExec :
ex-00000006: proxy auth state: UNCHALLENGED
2020-10-02 16:48:32.096 DEBUG [main] o.a.h.c.http.impl.classic.ConnectExec :
ex-00000006: acquiring connection with route
{s}->https://github-production-release-asset-2e65be.s3.amazonaws.com:443
2020-10-02 16:48:32.096 DEBUG [main] o.a.h.c.h.i.classic.InternalHttpClient :
ex-00000006: acquiring endpoint (3 MINUTES)
2020-10-02 16:48:32.096 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ex-00000006: endpoint lease request (3 MINUTES) [route:
{s}->https://github-production-release-asset-2e65be.s3.amazonaws.com:443][total
available: 6; route allocated: 1 of 5; total allocated: 6 of 6]
2020-10-02 16:48:32.097 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ex-00000006: endpoint leased [route:
{s}->https://github-production-release-asset-2e65be.s3.amazonaws.com:443][total
available: 5; route allocated: 1 of 5; total allocated: 6 of 6]
2020-10-02 16:48:32.097 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ex-00000006: acquired ep-00000007
2020-10-02 16:48:32.097 DEBUG [main] o.a.h.c.h.i.classic.InternalHttpClient :
ex-00000006: acquired endpoint ep-00000007
2020-10-02 16:48:32.097 DEBUG [main] o.a.h.c.h.impl.classic.MainClientExec :
ex-00000006: executing GET
/23216272/1a38ec80-d0ce-11ea-9065-30a975f676ad?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAIWNJYAX4CSVEH53A%2F20201002%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201002T084720Z&X-Amz-Expires=300&X-Amz-Signature=85155cda2ff7f56e5b04e3f8b7d46d1ed5710d6fb53cc79cbfe44c20ab19b1be&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=23216272&response-content-disposition=attachment%3B%20filename%3DGit-2.28.0-64-bit.exe&response-content-type=application%2Foctet-stream
HTTP/1.1
2020-10-02 16:48:32.097 DEBUG [main] o.a.h.c.h.i.classic.InternalHttpClient :
ep-00000007: start execution ex-00000006
2020-10-02 16:48:32.097 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ep-00000007: executing exchange ex-00000006 over http-outgoing-1
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> GET
/23216272/1a38ec80-d0ce-11ea-9065-30a975f676ad?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAIWNJYAX4CSVEH53A%2F20201002%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201002T084720Z&X-Amz-Expires=300&X-Amz-Signature=85155cda2ff7f56e5b04e3f8b7d46d1ed5710d6fb53cc79cbfe44c20ab19b1be&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=23216272&response-content-disposition=attachment%3B%20filename%3DGit-2.28.0-64-bit.exe&response-content-type=application%2Foctet-stream
HTTP/1.1
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> If-Modified-Since: Fri, 02 Oct 2020 08:47:31 GMT
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> Accept-Encoding: gzip, x-gzip, deflate
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> Host: github-production-release-asset-2e65be.s3.amazonaws.com
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> Connection: keep-alive
2020-10-02 16:48:32.097 DEBUG [main] org.apache.hc.client5.http.headers :
http-outgoing-1 >> User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.121 Safari/537.36
2020-10-02 16:48:32.099 DEBUG [main] h.i.i.DefaultManagedHttpClientConnection :
http-outgoing-1: Close connection
2020-10-02 16:48:32.100 DEBUG [main] o.a.h.c.h.i.classic.InternalHttpClient :
ep-00000007: endpoint closed
2020-10-02 16:48:32.100 DEBUG [main] o.a.h.c.h.i.classic.InternalHttpClient :
ep-00000007: discarding endpoint
2020-10-02 16:48:32.100 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ep-00000007: releasing endpoint
2020-10-02 16:48:32.100 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ep-00000007: connection is not kept alive
2020-10-02 16:48:32.100 DEBUG [main] h.i.i.PoolingHttpClientConnectionManager :
ep-00000007: connection released [route:
{s}->https://github-production-release-asset-2e65be.s3.amazonaws.com:443][total
available: 5; route allocated: 0 of 5; total allocated: 5 of 6]
2020-10-02 16:48:32.103 DEBUG [main] o.a.h.c.h.i.c.HttpRequestRetryExec :
ex-00000006: The target server failed to respond
org.apache.hc.core5.http.NoHttpResponseException: The target server failed to
respond
at
org.apache.hc.core5.http.impl.io.DefaultHttpResponseParser.createConnectionClosedException(DefaultHttpResponseParser.java:87)
{noformat}
and the counterpart in Wireshark is:
{noformat}
...
1959 10.750711 192.168.11.3 52.216.114.219 TLSv1.2 882
Application Data
1960 10.754755 192.168.11.3 52.216.114.219 TLSv1.2 85
Encrypted Alert
1961 10.756275 192.168.11.3 52.216.114.219 TCP 54 49900 →
443 [FIN, ACK] Seq=2274 Ack=3828 Win=130560 Len=0
1962 10.769308 192.168.11.3 52.216.114.219 TCP 66 49905 →
443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 WS=256 SACK_PERM=1
1963 11.011468 52.216.114.219 192.168.11.3 TCP 54 443 →
49900 [RST] Seq=3828 Win=0 Len=0
1964 11.013167 52.216.114.219 192.168.11.3 TCP 54 443 →
49900 [RST] Seq=3828 Win=0 Len=0
...
{noformat}
So we are actively closing the connection as you can see by the FIN/ACK right
after the requests headers have been sent. The servers sends a reset. [~olegk],
feel free to correct me if I am wrong.
[~jkmlee], can you enable {{-Djavax.net.debug=all}} and run the test again
along with a new Wireshark dump? I current do not understand who is actually
calling the close on our connection and why. Can you also try another Java
version? 8, 13, 14, 15 or maybe from another network connection?
> Difference in behavior between 4.5.x and 5.0.x - CloseableHttpClient returns
> 403 after NoHttpResponseException
> --------------------------------------------------------------------------------------------------------------
>
> Key: HTTPCLIENT-2118
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2118
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic), HttpClient (Windows)
> Affects Versions: 5.0.2
> Environment: Microsoft Windows 10 version 2004 [10.0.19041.508]
> Oracle JDK 11.0.8
> Reporter: Michael Lee
> Priority: Major
> Attachments: all_except_wire.log, all_except_wire.setMaxTotal5.log,
> all_except_wire.setMaxTotal6.log, demo.zip, headers.log, test_output.txt,
> wireshark.pcapng
>
>
> My application reuses an instance of CloseableHttpClient to retrieve the
> content from a list of URLs. After upgrading HttpClient from 4.5.x to 5.0.2
> (also 5.0 and 5.0.1), it always gets a NoHttpResponseException followed by a
> response code of 403 for a particular URL in the list. When using 4.5.x, it
> always gets a 200 or 304 for that particular URL.
> The behavior may be different if the order of the URLs in the list is changed.
> To illustrate the problem, I have extracted code from my application into the
> sample Maven project attached. In the JUnit test, testHttpClient4() will get
> either 200 or 304 for all the URLs. On the other hand, testHttpClient5()
> always gets 403 for the last URL in the list. In this project, I
> intentionally added a If-Modified-Since header with the value being current
> time minus 1 minute so that we should get a 304 from most of the URLs.
> Can you investigate if this is really an obscure bug or an undocumented
> behavior change related to how CloseableHttpClient handles redirects?
> Thanks.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
