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: [email protected]
For additional commands, e-mail: [email protected]
