Igor Fedorenko created HTTPCLIENT-1340:
------------------------------------------
Summary: ProtocolException when Connection:close response header
is present
Key: HTTPCLIENT-1340
URL: https://issues.apache.org/jira/browse/HTTPCLIENT-1340
Project: HttpComponents HttpClient
Issue Type: Bug
Affects Versions: 4.3 Beta1, 4.2.4
Reporter: Igor Fedorenko
The problem was originally observed when using maven 3.0.5 and newer with maven
repositories served by nginx that has username/password authentication and
connection keep-alive enabled.
I was able to reproduce the problem using standalone test application that
executes the same HttpGet request in a loop. Below is wire log of the last two
iterations that lead to "ProtocolException: The server failed to respond with a
valid HTTP response". From the log the client apparently stopped processing of
the response with Connection:close heaader and then reused the connection for
the next request.
{noformat}
2013/04/12 11:48:02:745 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl - Stale
connection check
2013/04/12 11:48:02:746 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Attempt 1 to execute request
2013/04/12 11:48:02:747 EDT [DEBUG] wire - >> "GET
/content/groups/sonatype-grid/.meta/prefixes.txt HTTP/1.1[\r][\n]"
2013/04/12 11:48:02:747 EDT [DEBUG] wire - >> "Host:
repository.sonatype.org[\r][\n]"
2013/04/12 11:48:02:747 EDT [DEBUG] wire - >> "Connection: Keep-Alive[\r][\n]"
2013/04/12 11:48:02:747 EDT [DEBUG] wire - >> "[\r][\n]"
2013/04/12 11:48:02:782 EDT [DEBUG] wire - << "HTTP/1.1 401
Unauthorized[\r][\n]"
2013/04/12 11:48:02:782 EDT [DEBUG] wire - << "Server: nginx/0.8.54[\r][\n]"
2013/04/12 11:48:02:782 EDT [DEBUG] wire - << "Date: Fri, 12 Apr 2013 15:48:02
GMT[\r][\n]"
2013/04/12 11:48:02:782 EDT [DEBUG] wire - << "Connection: keep-alive[\r][\n]"
2013/04/12 11:48:02:782 EDT [DEBUG] wire - << "Keep-Alive: timeout=5[\r][\n]"
2013/04/12 11:48:02:783 EDT [DEBUG] wire - << "Set-Cookie: rememberMe=deleteMe;
Path=/; Max-Age=0; Expires=Thu, 11-Apr-2013 15:48:02 GMT[\r][\n]"
2013/04/12 11:48:02:783 EDT [DEBUG] wire - << "WWW-Authenticate: BASIC
realm="Sonatype Nexus Repository Manager"[\r][\n]"
2013/04/12 11:48:02:783 EDT [DEBUG] wire - << "Content-Length: 0[\r][\n]"
2013/04/12 11:48:02:783 EDT [DEBUG] wire - << "[\r][\n]"
2013/04/12 11:48:02:783 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Connection can be kept alive for 5000 MILLISECONDS
2013/04/12 11:48:02:783 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Authentication required
2013/04/12 11:48:02:783 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
repository.sonatype.org:443 requested authentication
2013/04/12 11:48:02:795 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Selected authentication options: [BASIC]
2013/04/12 11:48:02:796 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Attempt 2 to execute request
2013/04/12 11:48:02:796 EDT [DEBUG] wire - >> "GET
/content/groups/sonatype-grid/.meta/prefixes.txt HTTP/1.1[\r][\n]"
2013/04/12 11:48:02:796 EDT [DEBUG] wire - >> "Host:
repository.sonatype.org[\r][\n]"
2013/04/12 11:48:02:796 EDT [DEBUG] wire - >> "Connection: Keep-Alive[\r][\n]"
2013/04/12 11:48:02:796 EDT [DEBUG] wire - >> "Authorization: Basic XXX
[\r][\n]"
2013/04/12 11:48:02:796 EDT [DEBUG] wire - >> "[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "HTTP/1.1 200 OK[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Server: nginx/0.8.54[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Date: Fri, 12 Apr 2013 15:48:02
GMT[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Content-Type: text/plain[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Connection: keep-alive[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Keep-Alive: timeout=5[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Set-Cookie: rememberMe=deleteMe;
Path=/; Max-Age=0; Expires=Thu, 11-Apr-2013 15:48:02 GMT[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "Last-Modified: Fri, 12 Apr 2013
08:22:54 GMT[\r][\n]"
2013/04/12 11:48:02:840 EDT [DEBUG] wire - << "ETag:
"{SHA1{3cf8e81cedbd285b8c745289d7184315762ca578}}"[\r][\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "Vary: Accept-Charset,
Accept-Encoding, Accept-Language, Accept[\r][\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "X-Content-Type-Options:
nosniff[\r][\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "Content-Length: 100[\r][\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "[\r][\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Connection can be kept alive for 5000 MILLISECONDS
2013/04/12 11:48:02:841 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Authentication succeeded
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "@ unsupported[\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "# Prefix file generated by
Sonatype Nexus[\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] wire - << "# Do not edit, changes will be
overwritten![\n]"
2013/04/12 11:48:02:841 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl - Stale
connection check
2013/04/12 11:48:02:843 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Attempt 1 to execute request
2013/04/12 11:48:02:843 EDT [DEBUG] wire - >> "GET
/content/groups/sonatype-grid/.meta/prefixes.txt HTTP/1.1[\r][\n]"
2013/04/12 11:48:02:843 EDT [DEBUG] wire - >> "Host:
repository.sonatype.org[\r][\n]"
2013/04/12 11:48:02:843 EDT [DEBUG] wire - >> "Connection: Keep-Alive[\r][\n]"
2013/04/12 11:48:02:843 EDT [DEBUG] wire - >> "[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "HTTP/1.1 401
Unauthorized[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Server: nginx/0.8.54[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Date: Fri, 12 Apr 2013 15:48:02
GMT[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Connection: keep-alive[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Keep-Alive: timeout=5[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Set-Cookie: rememberMe=deleteMe;
Path=/; Max-Age=0; Expires=Thu, 11-Apr-2013 15:48:02 GMT[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "WWW-Authenticate: BASIC
realm="Sonatype Nexus Repository Manager"[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "Content-Length: 0[\r][\n]"
2013/04/12 11:48:02:878 EDT [DEBUG] wire - << "[\r][\n]"
2013/04/12 11:48:02:879 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Connection can be kept alive for 5000 MILLISECONDS
2013/04/12 11:48:02:879 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Authentication required
2013/04/12 11:48:02:879 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
repository.sonatype.org:443 requested authentication
2013/04/12 11:48:02:879 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Selected authentication options: [BASIC]
2013/04/12 11:48:02:879 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Attempt 2 to execute request
2013/04/12 11:48:02:879 EDT [DEBUG] wire - >> "GET
/content/groups/sonatype-grid/.meta/prefixes.txt HTTP/1.1[\r][\n]"
2013/04/12 11:48:02:879 EDT [DEBUG] wire - >> "Host:
repository.sonatype.org[\r][\n]"
2013/04/12 11:48:02:879 EDT [DEBUG] wire - >> "Connection: Keep-Alive[\r][\n]"
2013/04/12 11:48:02:879 EDT [DEBUG] wire - >> "Authorization: Basic XXX
[\r][\n]"
2013/04/12 11:48:02:879 EDT [DEBUG] wire - >> "[\r][\n]"
2013/04/12 11:48:02:924 EDT [DEBUG] wire - << "HTTP/1.1 200 OK[\r][\n]"
2013/04/12 11:48:02:924 EDT [DEBUG] wire - << "Server: nginx/0.8.54[\r][\n]"
2013/04/12 11:48:02:924 EDT [DEBUG] wire - << "Date: Fri, 12 Apr 2013 15:48:02
GMT[\r][\n]"
2013/04/12 11:48:02:924 EDT [DEBUG] wire - << "Content-Type: text/plain[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "Connection: close[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "Set-Cookie: rememberMe=deleteMe;
Path=/; Max-Age=0; Expires=Thu, 11-Apr-2013 15:48:02 GMT[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "Last-Modified: Fri, 12 Apr 2013
08:22:54 GMT[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "ETag:
"{SHA1{3cf8e81cedbd285b8c745289d7184315762ca578}}"[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "Vary: Accept-Charset,
Accept-Encoding, Accept-Language, Accept[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "X-Content-Type-Options:
nosniff[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "Content-Length: 100[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] wire - << "[\r][\n]"
2013/04/12 11:48:02:925 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Authentication succeeded
2013/04/12 11:48:02:925 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl - Stale
connection check
2013/04/12 11:48:02:926 EDT [DEBUG] DownloadMain$DefaultHttpClientImpl -
Attempt 1 to execute request
2013/04/12 11:48:02:926 EDT [DEBUG] wire - >> "GET
/content/groups/sonatype-grid/.meta/prefixes.txt HTTP/1.1[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - >> "Host:
repository.sonatype.org[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - >> "Connection: Keep-Alive[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - >> "[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - << "@ unsupported[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - << "# Prefix file generated by
Sonatype Nexus[\r][\n]"
2013/04/12 11:48:02:926 EDT [DEBUG] wire - << "# Do not edit, changes will be
overwritten![\r][\n]"
50 4975
Exception in thread "main" org.apache.http.client.ClientProtocolException
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:909)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at download.httpclient.ssl.DownloadMain.run(DownloadMain.java:80)
at download.httpclient.ssl.DownloadMain.main(DownloadMain.java:31)
Caused by: org.apache.http.ProtocolException: The server failed to respond with
a valid HTTP response
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:103)
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at
org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at
org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at
org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at
org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at
org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at
org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at
org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:716)
at
org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:521)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
... 4 more
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
