org.apache.http.client.ClientProtocolException

hc-dev | Arthur Pilyuk (JIRA) | 3 years ago
  1. 0

    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}

    Apache's JIRA Issue Tracker | 4 years ago | Igor Fedorenko
    org.apache.http.client.ClientProtocolException
  2. Speed up your debug routine!

    Automated exception search integrated into your IDE

    4 unregistered visitors
    Not finding the right solution?
    Take a tour to get the most out of Samebug.

    Tired of useless tips?

    Automated exception search integrated into your IDE

    Root Cause Analysis

    1. org.apache.http.ProtocolException

      The server failed to respond with a valid HTTP response

      at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead()
    2. Apache HttpClient
      DefaultHttpResponseParser.parseHead
      1. org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:103)
      2. org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
      2 frames
    3. Apache Http
      AbstractHttpClientConnection.receiveResponseHeader
      1. org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
      2. org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
      2 frames
    4. Apache HttpClient
      ManagedClientConnectionImpl.receiveResponseHeader
      1. org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
      2. org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
      2 frames
    5. Apache Http
      HttpRequestExecutor.execute
      1. org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
      2. org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
      2 frames
    6. Apache HttpClient
      AbstractHttpClient.execute
      1. org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:716)
      2. org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:521)
      3. org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
      4. org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
      5. org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
      5 frames
    7. download.httpclient.ssl
      DownloadMain.main
      1. download.httpclient.ssl.DownloadMain.run(DownloadMain.java:80)
      2. download.httpclient.ssl.DownloadMain.main(DownloadMain.java:31)
      2 frames