You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by "Oleg Kalnichevski (JIRA)" <ji...@apache.org> on 2019/07/31 13:50:00 UTC
[jira] [Comment Edited] (HTTPCLIENT-2006) HttpClient 5.0-beta5 gets
403 error for URL, works in HttpClient 4/Curl/Wget etc
[ https://issues.apache.org/jira/browse/HTTPCLIENT-2006?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16897180#comment-16897180 ]
Oleg Kalnichevski edited comment on HTTPCLIENT-2006 at 7/31/19 1:49 PM:
------------------------------------------------------------------------
{noformat}
2019-07-31 14:24:07,007 main ERROR Unable to locate appender "Console" for logger config "org.apache.hc.client5.http"
2019-07-31 14:24:07,009 main ERROR Unable to locate appender "Console" for logger config "org.apache.hc.client5.http.wire"
2019-07-31 14:24:07,114 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: preparing request execution
2019-07-31 14:24:07,119 DEBUG [org.apache.hc.client5.http.protocol.RequestAddCookies] CookieSpec selected: standard
2019-07-31 14:24:07,122 DEBUG [org.apache.hc.client5.http.protocol.RequestAuthCache] Auth cache not set in the context
2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ProtocolExec] ex-00000001: target auth state: UNCHALLENGEDText
2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ProtocolExec] ex-00000001: proxy auth state: UNCHALLENGED
2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ConnectExec] ex-00000001: acquiring connection with route \{s}->https://www.popsugar.com:443
2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: acquiring endpoint (3 MINUTES)
2019-07-31 14:24:07,124 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: endpoint lease request (3 MINUTES) [route: \{s}->https://www.popsugar.com:443][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 200]
2019-07-31 14:24:07,127 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: endpoint leased [route: \{s}->https://www.popsugar.com:443][total kept alive: 0; route allocated: 1 of 100; total allocated: 1 of 200]
2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: acquired ep-00000000
2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: acquired endpoint ep-00000000
2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.ConnectExec] ex-00000001: opening connection \{s}->https://www.popsugar.com:443
2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: connecting endpoint (3 MINUTES)
2019-07-31 14:24:07,135 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connecting endpoint to https://www.popsugar.com:443 (3 MINUTES)
2019-07-31 14:24:07,138 DEBUG [org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator] http-outgoing-0: connecting to www.popsugar.com/13.224.2.79:443
2019-07-31 14:24:07,139 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Connecting socket to www.popsugar.com/13.224.2.79:443 with timeout 3 MINUTES
2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Enabled protocols: [TLSv1.3, TLSv1.2]
2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Enabled cipher suites:[TLS_AES_128_GCM_SHA256, TLS_AES_256_GCM_SHA384, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, 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_RSA_WITH_CHACHA20_POLY1305_SHA256, 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_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_EMPTY_RENEGOTIATION_INFO_SCSV]
2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Starting handshake
2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Secure session established
2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] negotiated protocol: TLSv1.2
2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] peer principal: CN=*.popsugar.com
2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] peer alternative names: [*.popsugar.com, *.popsu.gr, popsu.gr, popsugar.com, *.popsugar.co.uk, popsugar.co.uk, *.popsugar.com.au, popsugar.com.au, *.popsugar.fr, popsugar.fr, *.popsugar.de, popsugar.de, *.popsugar.tv, popsugar.tv]
2019-07-31 14:24:07,825 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] issuer principal: CN=Amazon, OU=Server CA 1B, O=Amazon, C=US
2019-07-31 14:24:07,827 DEBUG [org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator] http-outgoing-0: connection established 10.6.4.185:51644<->13.224.2.79:443
2019-07-31 14:24:07,827 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connected http-outgoing-0
2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: endpoint connected
2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.MainClientExec] ex-00000001: executing GET / HTTP/1.1
2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: start execution ex-00000001
2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: executing exchange ex-00000001 over http-outgoing-0
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> GET / HTTP/1.1
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Accept-Encoding: deflate, gzip, x-gzip
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Host: www.popsugar.com
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Connection: keep-alive
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> User-Agent: Apache-HttpClient/5.0-beta5 (Java/12)
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"
2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Accept-Encoding: deflate, gzip, x-gzip[\r][\n]"
2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Host: www.popsugar.com[\r][\n]"
2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Connection: keep-alive[\r][\n]"
2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "User-Agent: Apache-HttpClient/5.0-beta5 (Java/12)[\r][\n]"
2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "[\r][\n]"
2019-07-31 14:24:08,220 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "HTTP/1.1 403 Forbidden[\r][\n]"
2019-07-31 14:24:08,220 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Transfer-Encoding: chunked[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Connection: keep-alive[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Date: Wed, 31 Jul 2019 13:24:08 GMT[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Server: nginx/1.14.1[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Powered-By: PHP/7.2.18[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: PHPSESSID=a467994c4cae6da3d22022aff63fd769; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: client_locale=CA; expires=Thu, 01-Aug-2019 13:24:08 GMT; Max-Age=86400; path=/[\r][\n]"
2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: ss1=0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVYrdPbW%2BzkMi9murqh8mv%2F9DPFhFZ98OAlNG4R3Cwup1Nqmo%2BaucRS1Dx%2FeKkXuGQ6CjvroNI2Nd91TvrzrHK%2FkxDMqzOKjga%2F6px5Kr62g%2FsqAKnc%2FmtoMpvDLXGexI7QJRk1a1vrg%3D%3D%7C3cdd6f61b7982fe337499c741dc817adaaf128c1; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Content-Encoding: gzip[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Vary: Accept-Encoding[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Cache: Error from cloudfront[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Via: 1.1 d8792dbd3191bbe722eba5b536b979c8.cloudfront.net (CloudFront)[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Amz-Cf-Pop: SEA19-C2[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Amz-Cf-Id: jEYWKJzMSsi8gs9Ry9ZtVdde9CdLpet-RQYZ5Yx8C78tLfZS9Cs2NQ==[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "14[\r][\n]"
2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[0x1f][0xffffff8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x3][0x3][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][\r][\n]"
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << HTTP/1.1 403 Forbidden
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Content-Type: text/html; charset=UTF-8
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Transfer-Encoding: chunked
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Connection: keep-alive
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Date: Wed, 31 Jul 2019 13:24:08 GMT
2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Server: nginx/1.14.1
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Powered-By: PHP/7.2.18
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: PHPSESSID=a467994c4cae6da3d22022aff63fd769; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: client_locale=CA; expires=Thu, 01-Aug-2019 13:24:08 GMT; Max-Age=86400; path=/
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: ss1=0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVYrdPbW%2BzkMi9murqh8mv%2F9DPFhFZ98OAlNG4R3Cwup1Nqmo%2BaucRS1Dx%2FeKkXuGQ6CjvroNI2Nd91TvrzrHK%2FkxDMqzOKjga%2F6px5Kr62g%2FsqAKnc%2FmtoMpvDLXGexI7QJRk1a1vrg%3D%3D%7C3cdd6f61b7982fe337499c741dc817adaaf128c1; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Content-Encoding: gzip
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Vary: Accept-Encoding
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Cache: Error from cloudfront
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Via: 1.1 d8792dbd3191bbe722eba5b536b979c8.cloudfront.net (CloudFront)
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Amz-Cf-Pop: SEA19-C2
2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Amz-Cf-Id: jEYWKJzMSsi8gs9Ry9ZtVdde9CdLpet-RQYZ5Yx8C78tLfZS9Cs2NQ==
2019-07-31 14:24:08,228 DEBUG [org.apache.hc.client5.http.impl.classic.MainClientExec] ex-00000001: connection can be kept alive for -1 MILLISECONDS
2019-07-31 14:24:08,230 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [PHPSESSID="a467994c4cae6da3d22022aff63fd769", domain:www.popsugar.com, path:/, expiry:Fri Aug 23 17:57:28 BST 2019]
2019-07-31 14:24:08,230 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [client_locale="CA", domain:www.popsugar.com, path:/, expiry:Thu Aug 01 14:24:08 BST 2019]
2019-07-31 14:24:08,231 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [ss1="0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVY...", domain:www.popsugar.com, path:/, expiry:Fri Aug 23 17:57:28 BST 2019]
2019-07-31 14:24:08,233 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "0[\r][\n]"
2019-07-31 14:24:08,233 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[\r][\n]"
2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: releasing valid endpoint
2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: releasing endpoint
2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connection http-outgoing-0 can be kept alive indefinitely
2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connection released [route: \{s}->https://www.popsugar.com:443][total kept alive: 1; route allocated: 1 of 100; total allocated: 1 of 200]
Exception in thread "main" org.apache.hc.client5.http.HttpResponseException: status code: 403, reason phrase: Forbidden
at org.apache.hc.client5.http.impl.classic.AbstractHttpClientResponseHandler.handleResponse(AbstractHttpClientResponseHandler.java:68)
at org.apache.hc.client5.http.fluent.Response.handleResponse(Response.java:96)
at org.apache.hc.client5.http.fluent.Response.returnContent(Response.java:105)
at Test.main(Test.java:7)
{noformat}
was (Author: aparks):
{{2019-07-31 14:24:07,007 main ERROR Unable to locate appender "Console" for logger config "org.apache.hc.client5.http"}}
{{2019-07-31 14:24:07,009 main ERROR Unable to locate appender "Console" for logger config "org.apache.hc.client5.http.wire"}}
{{2019-07-31 14:24:07,114 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: preparing request execution}}
{{2019-07-31 14:24:07,119 DEBUG [org.apache.hc.client5.http.protocol.RequestAddCookies] CookieSpec selected: standard}}
{{2019-07-31 14:24:07,122 DEBUG [org.apache.hc.client5.http.protocol.RequestAuthCache] Auth cache not set in the context}}
{{2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ProtocolExec] ex-00000001: target auth state: UNCHALLENGED}}
{{2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ProtocolExec] ex-00000001: proxy auth state: UNCHALLENGED}}
{{2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.ConnectExec] ex-00000001: acquiring connection with route \{s}->https://www.popsugar.com:443}}
{{2019-07-31 14:24:07,123 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: acquiring endpoint (3 MINUTES)}}
{{2019-07-31 14:24:07,124 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: endpoint lease request (3 MINUTES) [route: \{s}->https://www.popsugar.com:443][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 200]}}
{{2019-07-31 14:24:07,127 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: endpoint leased [route: \{s}->https://www.popsugar.com:443][total kept alive: 0; route allocated: 1 of 100; total allocated: 1 of 200]}}
{{2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ex-00000001: acquired ep-00000000}}
{{2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ex-00000001: acquired endpoint ep-00000000}}
{{2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.ConnectExec] ex-00000001: opening connection \{s}->https://www.popsugar.com:443}}
{{2019-07-31 14:24:07,134 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: connecting endpoint (3 MINUTES)}}
{{2019-07-31 14:24:07,135 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connecting endpoint to https://www.popsugar.com:443 (3 MINUTES)}}
{{2019-07-31 14:24:07,138 DEBUG [org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator] http-outgoing-0: connecting to www.popsugar.com/13.224.2.79:443}}
{{2019-07-31 14:24:07,139 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Connecting socket to www.popsugar.com/13.224.2.79:443 with timeout 3 MINUTES}}
{{2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Enabled protocols: [TLSv1.3, TLSv1.2]}}
{{2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Enabled cipher suites:[TLS_AES_128_GCM_SHA256, TLS_AES_256_GCM_SHA384, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, 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_RSA_WITH_CHACHA20_POLY1305_SHA256, 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_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_EMPTY_RENEGOTIATION_INFO_SCSV]}}
{{2019-07-31 14:24:07,346 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Starting handshake}}
{{2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] Secure session established}}
{{2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] negotiated protocol: TLSv1.2}}
{{2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256}}
{{2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] peer principal: CN=*.popsugar.com}}
{{2019-07-31 14:24:07,824 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] peer alternative names: [*.popsugar.com, *.popsu.gr, popsu.gr, popsugar.com, *.popsugar.co.uk, popsugar.co.uk, *.popsugar.com.au, popsugar.com.au, *.popsugar.fr, popsugar.fr, *.popsugar.de, popsugar.de, *.popsugar.tv, popsugar.tv]}}
{{2019-07-31 14:24:07,825 DEBUG [org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory] issuer principal: CN=Amazon, OU=Server CA 1B, O=Amazon, C=US}}
{{2019-07-31 14:24:07,827 DEBUG [org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator] http-outgoing-0: connection established 10.6.4.185:51644<->13.224.2.79:443}}
{{2019-07-31 14:24:07,827 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connected http-outgoing-0}}
{{2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: endpoint connected}}
{{2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.MainClientExec] ex-00000001: executing GET / HTTP/1.1}}
{{2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: start execution ex-00000001}}
{{2019-07-31 14:24:07,828 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: executing exchange ex-00000001 over http-outgoing-0}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> GET / HTTP/1.1}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Accept-Encoding: deflate, gzip, x-gzip}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Host: www.popsugar.com}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> Connection: keep-alive}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 >> User-Agent: Apache-HttpClient/5.0-beta5 (Java/12)}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"}}
{{2019-07-31 14:24:07,829 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Accept-Encoding: deflate, gzip, x-gzip[\r][\n]"}}
{{2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Host: www.popsugar.com[\r][\n]"}}
{{2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "Connection: keep-alive[\r][\n]"}}
{{2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "User-Agent: Apache-HttpClient/5.0-beta5 (Java/12)[\r][\n]"}}
{{2019-07-31 14:24:07,830 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 >> "[\r][\n]"}}
{{2019-07-31 14:24:08,220 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "HTTP/1.1 403 Forbidden[\r][\n]"}}
{{2019-07-31 14:24:08,220 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Content-Type: text/html; charset=UTF-8[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Transfer-Encoding: chunked[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Connection: keep-alive[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Date: Wed, 31 Jul 2019 13:24:08 GMT[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Server: nginx/1.14.1[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Powered-By: PHP/7.2.18[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: PHPSESSID=a467994c4cae6da3d22022aff63fd769; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: client_locale=CA; expires=Thu, 01-Aug-2019 13:24:08 GMT; Max-Age=86400; path=/[\r][\n]"}}
{{2019-07-31 14:24:08,221 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Set-Cookie: ss1=0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVYrdPbW%2BzkMi9murqh8mv%2F9DPFhFZ98OAlNG4R3Cwup1Nqmo%2BaucRS1Dx%2FeKkXuGQ6CjvroNI2Nd91TvrzrHK%2FkxDMqzOKjga%2F6px5Kr62g%2FsqAKnc%2FmtoMpvDLXGexI7QJRk1a1vrg%3D%3D%7C3cdd6f61b7982fe337499c741dc817adaaf128c1; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Content-Encoding: gzip[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Vary: Accept-Encoding[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Cache: Error from cloudfront[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "Via: 1.1 d8792dbd3191bbe722eba5b536b979c8.cloudfront.net (CloudFront)[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Amz-Cf-Pop: SEA19-C2[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "X-Amz-Cf-Id: jEYWKJzMSsi8gs9Ry9ZtVdde9CdLpet-RQYZ5Yx8C78tLfZS9Cs2NQ==[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "14[\r][\n]"}}
{{2019-07-31 14:24:08,222 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[0x1f][0xffffff8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x3][0x3][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][\r][\n]"}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << HTTP/1.1 403 Forbidden}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Content-Type: text/html; charset=UTF-8}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Transfer-Encoding: chunked}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Connection: keep-alive}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Date: Wed, 31 Jul 2019 13:24:08 GMT}}
{{2019-07-31 14:24:08,224 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Server: nginx/1.14.1}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Powered-By: PHP/7.2.18}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: PHPSESSID=a467994c4cae6da3d22022aff63fd769; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: client_locale=CA; expires=Thu, 01-Aug-2019 13:24:08 GMT; Max-Age=86400; path=/}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Set-Cookie: ss1=0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVYrdPbW%2BzkMi9murqh8mv%2F9DPFhFZ98OAlNG4R3Cwup1Nqmo%2BaucRS1Dx%2FeKkXuGQ6CjvroNI2Nd91TvrzrHK%2FkxDMqzOKjga%2F6px5Kr62g%2FsqAKnc%2FmtoMpvDLXGexI7QJRk1a1vrg%3D%3D%7C3cdd6f61b7982fe337499c741dc817adaaf128c1; expires=Fri, 23-Aug-2019 16:57:28 GMT; Max-Age=2000000; path=/}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Content-Encoding: gzip}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Vary: Accept-Encoding}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Cache: Error from cloudfront}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << Via: 1.1 d8792dbd3191bbe722eba5b536b979c8.cloudfront.net (CloudFront)}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Amz-Cf-Pop: SEA19-C2}}
{{2019-07-31 14:24:08,225 DEBUG [org.apache.hc.client5.http.headers] http-outgoing-0 << X-Amz-Cf-Id: jEYWKJzMSsi8gs9Ry9ZtVdde9CdLpet-RQYZ5Yx8C78tLfZS9Cs2NQ==}}
{{2019-07-31 14:24:08,228 DEBUG [org.apache.hc.client5.http.impl.classic.MainClientExec] ex-00000001: connection can be kept alive for -1 MILLISECONDS}}
{{2019-07-31 14:24:08,230 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [PHPSESSID="a467994c4cae6da3d22022aff63fd769", domain:www.popsugar.com, path:/, expiry:Fri Aug 23 17:57:28 BST 2019]}}
{{2019-07-31 14:24:08,230 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [client_locale="CA", domain:www.popsugar.com, path:/, expiry:Thu Aug 01 14:24:08 BST 2019]}}
{{2019-07-31 14:24:08,231 DEBUG [org.apache.hc.client5.http.protocol.ResponseProcessCookies] Cookie accepted [ss1="0%7C1566579448%7CPoe4MvFPEpASQmkBq6hXHVbh%2BdeJBrREDekNsj2Fw8%2Bdz6MEs7BYs%2Ba9vW5UeSodMb1SR2j0trhVY...", domain:www.popsugar.com, path:/, expiry:Fri Aug 23 17:57:28 BST 2019]}}
{{2019-07-31 14:24:08,233 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "0[\r][\n]"}}
{{2019-07-31 14:24:08,233 DEBUG [org.apache.hc.client5.http.wire] http-outgoing-0 << "[\r][\n]"}}
{{2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.classic.InternalHttpClient] ep-00000000: releasing valid endpoint}}
{{2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: releasing endpoint}}
{{2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connection http-outgoing-0 can be kept alive indefinitely}}
{{2019-07-31 14:24:08,234 DEBUG [org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager] ep-00000000: connection released [route: \{s}->https://www.popsugar.com:443][total kept alive: 1; route allocated: 1 of 100; total allocated: 1 of 200]}}
{{Exception in thread "main" org.apache.hc.client5.http.HttpResponseException: status code: 403, reason phrase: Forbidden}}
{{ at org.apache.hc.client5.http.impl.classic.AbstractHttpClientResponseHandler.handleResponse(AbstractHttpClientResponseHandler.java:68)}}
{{ at org.apache.hc.client5.http.fluent.Response.handleResponse(Response.java:96)}}
{{ at org.apache.hc.client5.http.fluent.Response.returnContent(Response.java:105)}}
{{ at Test.main(Test.java:7)}}
> HttpClient 5.0-beta5 gets 403 error for URL, works in HttpClient 4/Curl/Wget etc
> --------------------------------------------------------------------------------
>
> Key: HTTPCLIENT-2006
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2006
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic)
> Affects Versions: 5.0 Beta5
> Environment: Java 12/MacOS 10.14.6
> Reporter: Andrew Parks
> Priority: Major
>
> When testing an upgrade from HttpClient 4.5.9 to HttpClient 5.0-beta5, I tried the following code on a large number of URLs:
> {{System.out.println(Request.Get("https://www.popsugar.com").execute().returnContent());}}
> It worked fine for other sites, but for some reason, the PopSugar web site returns a 403 error. The same web site does not have a problem when HttpClient 4.5.9 is used to do exactly the same thing. There is also no problem when tested with curl, wget, or a regular browser. Changing user agents does not make a difference.
> I have verified that the PopSugar web site supports HTTP/2. Perhaps there is a protocol incompatibility.
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org