You are viewing a plain text version of this content. The canonical link for it is here.
Posted to httpclient-users@hc.apache.org by Deb <db...@yahoo.com> on 2010/05/14 18:35:15 UTC

Intermittent errors when sending compressed data to Apache

We have a Java client -> Apache httpd proxy -> Tomcat configuration that uses HttpClient to upload files to the Tomcat server by means of a HttpPost with a MultipartEntity. This worked fine until we added compression. That is, we:

1. Wrapped the MultipartEntity in a subclass of HttpEntityWrapper that sends content through GZIPOutputStream, setting content encoding to "gzip" and forcing transfer encoding to chunked. Content length is -1 (unknown). 

2. Turned on mod_deflate on the httpd server to decompress incoming requests.

With gzip compression enabled this way, we see intermittent errors on both the proxy server and Tomcat. Logging the HttpClient wire traffic, the initial request seems to be fine (lines truncated), but the other end sees errors, such as "Bad Request" or "Bad Gateway" (502):

10:24:34 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
10:24:34 http.wire - >> "Transfer-Encoding: chunked[EOL]"
10:24:34 http.wire - >> "Content-Type: multipart/form-data; boundary=ctYUiLJa87ve0N5X2gj9yrbkZ6...
10:24:34 http.wire - >> "Content-Encoding: gzip[EOL]"
10:24:34 http.wire - >> "Host: localhost[EOL]"
10:24:34 http.wire - >> "Connection: Keep-Alive[EOL]"
10:24:34 http.wire - >> "Cookie: JSESSIONID=F0BE26644BF132EEF29D70EE65FFB143[EOL]"
10:24:34 http.wire - >> "[EOL]"
10:24:34 http.wire - >> "2000[EOL]"
10:24:34 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0xec]
...
10:24:35 http.wire - >> "[EOL]"
10:24:35 http.wire - >> "0[EOL]"
10:24:35 http.wire - >> "[EOL]"
10:24:35 http.wire - << "HTTP/1.1 400 Bad Request[EOL]"
10:24:35 http.wire - << "Date: Fri, 14 May 2010 14:24:34 GMT[EOL]"
10:24:35 http.wire - << "Vary: Accept-Encoding[EOL]"
10:24:35 http.wire - << "Content-Length: 226[EOL]"
10:24:35 http.wire - << "Connection: close[EOL]"
10:24:35 http.wire - << "Content-Type: text/html; charset=iso-8859-1[EOL]"

The Apache httpd server's error log has messages like:

[Fri May 14 10:24:35 2010] [error] proxy: pass request body failed to 172.16.172.33:8080 (somehost) from 127.0.0.1 ()

Whereas the access log sometimes shows bizarre "0" requests like (with "invalid method" errors in error.log):

127.0.0.1 - - [14/May/2010:10:21:30 -0400] "0" 501 213

On the Tomcat side, we see "invalid chunk header" errors or just plain IOExceptions:

Caused by: java.io.IOException: Invalid chunk header
        at org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:133)
        at org.apache.coyote.http11.InternalInputBuffer.doRead(InternalInputBuffer.java:710)
        at org.apache.coyote.Request.doRead(Request.java:428)

Retrying the same file upload normally succeeds the second time. But sometimes during the retry HttpClient does weird things with the chunked transfer header. Notice the "800" lines in the first retry attempt below:

12:51:36 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
12:51:36 http.wire - >> "Transfer-Encoding: chunked[EOL]"
12:51:36 http.wire - >> "Content-Type: multipart/form-data; boundary=FhZo2qSHws5DvuQnMaQ49CDY9q_ay_V6
12:51:36 http.wire - >> "Content-Encoding: gzip[EOL]"
12:51:36 http.wire - >> "Host: lila-dev-local:80[EOL]"
12:51:36 http.wire - >> "Connection: Keep-Alive[EOL]"
12:51:36 http.wire - >> "Cookie: JSESSIONID=4B15E0DFA610BB54D4EE3CDE2BF710DC[EOL]"
12:51:36 http.wire - >> "[EOL]"
12:51:36 http.wire - >> "a[EOL]"
12:51:36 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0]"
12:51:36 http.wire - >> "[EOL]"
12:51:36 http.wire - >> "800[EOL]"
12:51:36 http.wire - >> "800[EOL]"
12:51:36 http.wire - >> "800[EOL]"
12:51:36 client.DefaultHttpClient - I/O exception (java.net.SocketException) caught when processing request: Software caused connection abort: socket write error
12:51:36 client.DefaultHttpClient - Retrying request
12:51:36 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
12:51:36 http.wire - >> "Transfer-Encoding: chunked[EOL]"
12:51:36 http.wire - >> "Content-Type: multipart/form-data; boundary=FhZo2qSHws5DvuQnMaQ49CDY9q_ay_V6
12:51:36 http.wire - >> "Content-Encoding: gzip[EOL]"
12:51:36 http.wire - >> "Host: lila-dev-local:80[EOL]"
12:51:36 http.wire - >> "Connection: Keep-Alive[EOL]"
12:51:36 http.wire - >> "Cookie: JSESSIONID=4B15E0DFA610BB54D4EE3CDE2BF710DC[EOL]"
12:51:36 http.wire - >> "[EOL]"
12:51:36 http.wire - >> "a[EOL]"
12:51:36 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0]"
12:51:36 http.wire - >> "[EOL]"
12:51:36 http.wire - >> "800[EOL]"
12:51:36 http.wire - >> "[0xec][0xbd][0x9][0xb8]e[0xe7]U[0x1d][0xb8][0xdf][0xbd]O[0xaa]7[0xdd]{[0xcf]
12:51:36 http.wire - >> "[0xd3][0xbe]6|[0x9f]x[0x9f][0xa3]+[0x97][0xdf][0x1c][0xf6][0xa6][0xfb][0x8e]
...


Was wondering if anyone had insight on these intermittent errors we are experiencing.

Thanks!
Deb

---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org


Re: Intermittent errors when sending compressed data to Apache

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Fri, 2010-05-14 at 09:35 -0700, Deb wrote:
> We have a Java client -> Apache httpd proxy -> Tomcat configuration that uses HttpClient to upload files to the Tomcat server by means of a HttpPost with a MultipartEntity. This worked fine until we added compression. That is, we:
> 
> 1. Wrapped the MultipartEntity in a subclass of HttpEntityWrapper that sends content through GZIPOutputStream, setting content encoding to "gzip" and forcing transfer encoding to chunked. Content length is -1 (unknown). 
> 
> 2. Turned on mod_deflate on the httpd server to decompress incoming requests.
> 
> With gzip compression enabled this way, we see intermittent errors on both the proxy server and Tomcat. Logging the HttpClient wire traffic, the initial request seems to be fine (lines truncated), but the other end sees errors, such as "Bad Request" or "Bad Gateway" (502):
> 
> 10:24:34 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
> 10:24:34 http.wire - >> "Transfer-Encoding: chunked[EOL]"
> 10:24:34 http.wire - >> "Content-Type: multipart/form-data; boundary=ctYUiLJa87ve0N5X2gj9yrbkZ6...
> 10:24:34 http.wire - >> "Content-Encoding: gzip[EOL]"
> 10:24:34 http.wire - >> "Host: localhost[EOL]"
> 10:24:34 http.wire - >> "Connection: Keep-Alive[EOL]"
> 10:24:34 http.wire - >> "Cookie: JSESSIONID=F0BE26644BF132EEF29D70EE65FFB143[EOL]"
> 10:24:34 http.wire - >> "[EOL]"
> 10:24:34 http.wire - >> "2000[EOL]"
> 10:24:34 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0xec]
> ...
> 10:24:35 http.wire - >> "[EOL]"
> 10:24:35 http.wire - >> "0[EOL]"
> 10:24:35 http.wire - >> "[EOL]"
> 10:24:35 http.wire - << "HTTP/1.1 400 Bad Request[EOL]"
> 10:24:35 http.wire - << "Date: Fri, 14 May 2010 14:24:34 GMT[EOL]"
> 10:24:35 http.wire - << "Vary: Accept-Encoding[EOL]"
> 10:24:35 http.wire - << "Content-Length: 226[EOL]"
> 10:24:35 http.wire - << "Connection: close[EOL]"
> 10:24:35 http.wire - << "Content-Type: text/html; charset=iso-8859-1[EOL]"
> 
> The Apache httpd server's error log has messages like:
> 
> [Fri May 14 10:24:35 2010] [error] proxy: pass request body failed to 172.16.172.33:8080 (somehost) from 127.0.0.1 ()
> 
> Whereas the access log sometimes shows bizarre "0" requests like (with "invalid method" errors in error.log):
> 
> 127.0.0.1 - - [14/May/2010:10:21:30 -0400] "0" 501 213
> 
> On the Tomcat side, we see "invalid chunk header" errors or just plain IOExceptions:
> 
> Caused by: java.io.IOException: Invalid chunk header
>         at org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:133)
>         at org.apache.coyote.http11.InternalInputBuffer.doRead(InternalInputBuffer.java:710)
>         at org.apache.coyote.Request.doRead(Request.java:428)
> 
> Retrying the same file upload normally succeeds the second time. But sometimes during the retry HttpClient does weird things with the chunked transfer header. Notice the "800" lines in the first retry attempt below:
> 
> 12:51:36 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
> 12:51:36 http.wire - >> "Transfer-Encoding: chunked[EOL]"
> 12:51:36 http.wire - >> "Content-Type: multipart/form-data; boundary=FhZo2qSHws5DvuQnMaQ49CDY9q_ay_V6
> 12:51:36 http.wire - >> "Content-Encoding: gzip[EOL]"
> 12:51:36 http.wire - >> "Host: lila-dev-local:80[EOL]"
> 12:51:36 http.wire - >> "Connection: Keep-Alive[EOL]"
> 12:51:36 http.wire - >> "Cookie: JSESSIONID=4B15E0DFA610BB54D4EE3CDE2BF710DC[EOL]"
> 12:51:36 http.wire - >> "[EOL]"
> 12:51:36 http.wire - >> "a[EOL]"
> 12:51:36 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0]"
> 12:51:36 http.wire - >> "[EOL]"
> 12:51:36 http.wire - >> "800[EOL]"
> 12:51:36 http.wire - >> "800[EOL]"
> 12:51:36 http.wire - >> "800[EOL]"
> 12:51:36 client.DefaultHttpClient - I/O exception (java.net.SocketException) caught when processing request: Software caused connection abort: socket write error
> 12:51:36 client.DefaultHttpClient - Retrying request
> 12:51:36 http.wire - >> "POST /inbox/dicomImport/multiFile.html HTTP/1.1[EOL]"
> 12:51:36 http.wire - >> "Transfer-Encoding: chunked[EOL]"
> 12:51:36 http.wire - >> "Content-Type: multipart/form-data; boundary=FhZo2qSHws5DvuQnMaQ49CDY9q_ay_V6
> 12:51:36 http.wire - >> "Content-Encoding: gzip[EOL]"
> 12:51:36 http.wire - >> "Host: lila-dev-local:80[EOL]"
> 12:51:36 http.wire - >> "Connection: Keep-Alive[EOL]"
> 12:51:36 http.wire - >> "Cookie: JSESSIONID=4B15E0DFA610BB54D4EE3CDE2BF710DC[EOL]"
> 12:51:36 http.wire - >> "[EOL]"
> 12:51:36 http.wire - >> "a[EOL]"
> 12:51:36 http.wire - >> "[0x1f][0x8b][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0]"
> 12:51:36 http.wire - >> "[EOL]"
> 12:51:36 http.wire - >> "800[EOL]"
> 12:51:36 http.wire - >> "[0xec][0xbd][0x9][0xb8]e[0xe7]U[0x1d][0xb8][0xdf][0xbd]O[0xaa]7[0xdd]{[0xcf]
> 12:51:36 http.wire - >> "[0xd3][0xbe]6|[0x9f]x[0x9f][0xa3]+[0x97][0xdf][0x1c][0xf6][0xa6][0xfb][0x8e]
> ...
> 
> 
> Was wondering if anyone had insight on these intermittent errors we are experiencing.
> 
> Thanks!
> Deb
> 

Deb

I can't remember a single confirmed case of data corruption by
HttpClient for many years. So, my immediate guess of a cause of the
problem would be data loss in transit or connectivity problems (Software
caused connection abort exception seems to support that).

Try to narrow the problem down and find out whether chunk coding or data
compression is a contributing factor.  

(1) Disable content compression but force chunking
(2) Enable content compression but disable chunking by wrapping outgoing
entities with BufferingEntity in order to determine content length.

Also consider trying out HttpClient 4.1 (ALPHA) that provides support
for content compression out of the box.

Oleg


---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org