Can't upload big files via nginx as reverse proxy

speedfirst nginx-forum at nginx.us
Tue Jun 5 10:08:30 UTC 2012


retry the test while client_max_body_size=0;
The size of tmp file is as expected, about 3.7M :
root at zm-dev03:/opt/data/tmp/nginx/client# ll 0000000001 
-rw------- 1 speedfirst speedfirst 3914486 2012-06-06 01:27 0000000001

Here is the client script from curl:
curl -v -u admin at dev03.eng.test.com:test123 -F
"file=@test.tgz;filename=test.tgz;type=application/x-compressed-tar"
"http://dev03.eng.test.com/service/home/admin@dev03.eng.test.com/?fmt=tgz&resolve=reset"

Here is the debug_http nginx log.
2012/06/06 01:27:35 [debug] 15621#0: *5 http process request line
2012/06/06 01:27:35 [debug] 15621#0: *5 http request line: "POST
/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset HTTP/1.1"
2012/06/06 01:27:35 [debug] 15621#0: *5 http uri:
"/service/home/admin at dev03.eng.test.com/"
2012/06/06 01:27:35 [debug] 15621#0: *5 http args:
"fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http exten: ""
2012/06/06 01:27:35 [debug] 15621#0: *5 http process request header
line
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Authorization:
Basic YWRtaW5Aem0tZGV2MDMuZW5nLnZtd2FyZS5jb206dGVzdDEyMw=="
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "User-Agent:
curl/7.22.0 (x86_64-pc-linux-gnu) libcurl/7.22.0 OpenSSL/1.0.1
zlib/1.2.3.4 libidn/1.23 librtmp/2.3"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Host:
dev03.eng.vmware.com"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Accept: */*"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Content-Length:
3914486"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Expect:
100-continue"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header: "Content-Type:
multipart/form-data; boundary=----------------------------f9dbdf4f72b4"
2012/06/06 01:27:35 [debug] 15621#0: *5 http header done
2012/06/06 01:27:35 [debug] 15621#0: *5 rewrite phase: 0
2012/06/06 01:27:35 [debug] 15621#0: *5 test location: "/"
2012/06/06 01:27:35 [debug] 15621#0: *5 using configuration "/"
2012/06/06 01:27:35 [debug] 15621#0: *5 generic phase: 4
2012/06/06 01:27:35 [debug] 15621#0: *5 generic phase: 5
2012/06/06 01:27:35 [debug] 15621#0: *5 access phase: 6
2012/06/06 01:27:35 [debug] 15621#0: *5 access phase: 7
2012/06/06 01:27:35 [debug] 15621#0: *5 post access phase: 8
2012/06/06 01:27:35 [debug] 15621#0: *5 send 100 Continue
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3914486
2012/06/06 01:27:35 [debug] 15621#0: *5 http finalize request: -4,
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset" a:1,
c:2
2012/06/06 01:27:35 [debug] 15621#0: *5 http request count:2 blk:0
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
174
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3914312
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3914312
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3912952
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3912952
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3911592
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3910232
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3910232
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3908872
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3908872
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.eng.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3907512
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3907512
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1218
2012/06/06 01:27:35 [notice] 15621#0: *5 a client request body is
buffered to a temporary file
/opt/zimbra/data/tmp/nginx/client/0000000001, client: 10.112.117.117,
server: , request: "POST
/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset HTTP/1.1",
host: "dev03.test.com"
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1502
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3904792
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3904792
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:35 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3903432
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:35 [debug] 15621#0: *5 http client request body rest
3903432
2012/06/06 01:27:35 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
... ... ... <-- tens of similar log entries
2012/06/06 01:27:37 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body recv
1360
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body rest
1528
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body recv
-2
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body rest
1528
2012/06/06 01:27:37 [debug] 15621#0: *5 http run request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:37 [debug] 15621#0: *5 http read client request body
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body recv
1528
2012/06/06 01:27:37 [debug] 15621#0: *5 http client request body rest 0
2012/06/06 01:27:37 [debug] 15621#0: *5 http init upstream, client
timer: 0
2012/06/06 01:27:37 [debug] 15621#0: *5 http script copy:
"X-Forwarded-For: "
2012/06/06 01:27:37 [debug] 15621#0: *5 http script var:
"10.112.117.117"
2012/06/06 01:27:37 [debug] 15621#0: *5 http script copy: "

"
2012/06/06 01:27:37 [debug] 15621#0: *5 http script copy: "Host: "
2012/06/06 01:27:37 [debug] 15621#0: *5 http script var:
"dev03.test.com"
2012/06/06 01:27:37 [debug] 15621#0: *5 http script copy: "

"
2012/06/06 01:27:37 [debug] 15621#0: *5 http script copy: "Connection:
close

"
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header:
"Authorization: Basic
YWRtaW5Aem0tZGV2MDMuZW5nLnZtd2FyZS5jb206dGVzdDEyMw=="
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header: "User-Agent:
curl/7.22.0 (x86_64-pc-linux-gnu) libcurl/7.22.0 OpenSSL/1.0.1
zlib/1.2.3.4 libidn/1.23 librtmp/2.3"
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header: "Accept:
*/*"
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header:
"Content-Length: 3914486"
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header:
"Content-Type: multipart/form-data;
boundary=----------------------------f9dbdf4f72b4"
2012/06/06 01:27:37 [debug] 15621#0: *5 http proxy header:
"POST /service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset
HTTP/1.0

X-Forwarded-For: 10.112.117.117

Host: dev03.test.com

Connection: close

Authorization: Basic
YWRtaW5Aem0tZGV2MDMuZW5nLnZtd2FyZS5jb206dGVzdDEyMw==

User-Agent: curl/7.22.0 (x86_64-pc-linux-gnu) libcurl/7.22.0
OpenSSL/1.0.1 zlib/1.2.3.4 libidn/1.23 librtmp/2.3

Accept: */*

Content-Length: 3914486

Content-Type: multipart/form-data;
boundary=----------------------------f9dbdf4f72b4



"
2012/06/06 01:27:37 [debug] 15621#0: *5 http cleanup add:
0000000001D28F58
2012/06/06 01:27:37 [debug] 15621#0: *5 zmauth: prepare route for proxy
... ..<-- choose the upstream route
2012/06/06 01:27:37 [debug] 15621#0: *5 zmauth: prepare upstream
connection, try: 1
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream connect: -2
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream send request
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:27:37 [debug] 15621#0: *5 http upstream send request
2012/06/06 01:27:40 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:27:40 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:27:40 [debug] 15621#0: *5 http upstream send request
2012/06/06 01:27:44 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
... ... <--- tens of similar log entires
2012/06/06 01:28:19 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:28:19 [debug] 15621#0: *5 http upstream send request
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream send request
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream process header
2012/06/06 01:28:22 [debug] 15621#0: *5 http proxy status 200 "200 OK"
2012/06/06 01:28:22 [debug] 15621#0: *5 http proxy header: "Date: Tue,
05 Jun 2012 17:27:37 GMT"
2012/06/06 01:28:22 [debug] 15621#0: *5 http proxy header:
"Content-Type: text/html; charset=utf-8"
2012/06/06 01:28:22 [debug] 15621#0: *5 http proxy header: "Connection:
close"
2012/06/06 01:28:22 [debug] 15621#0: *5 http proxy header done
2012/06/06 01:28:22 [debug] 15621#0: *5 HTTP/1.1 200 OK

Server: nginx

Date: Tue, 05 Jun 2012 17:28:22 GMT

Content-Type: text/html; charset=utf-8

Transfer-Encoding: chunked

Connection: keep-alive


2012/06/06 01:28:22 [debug] 15621#0: *5 http write filter: l:0 f:0
s:163
2012/06/06 01:28:22 [debug] 15621#0: *5 http cacheable: 0
2012/06/06 01:28:22 [debug] 15621#0: *5 http upstream process upstream
2012/06/06 01:28:23 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:23 [debug] 15621#0: *5 http upstream send request
handler
2012/06/06 01:28:57 [debug] 15621#0: *5 http upstream request:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http upstream process upstream
2012/06/06 01:28:57 [debug] 15621#0: *5 http output filter
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http copy filter:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http postpone filter
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
0000000001D2A388
2012/06/06 01:28:57 [debug] 15621#0: *5 http chunk: 22
2012/06/06 01:28:57 [debug] 15621#0: *5 http write filter: l:0 f:0
s:191
2012/06/06 01:28:57 [debug] 15621#0: *5 http copy filter: 0
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http upstream exit:
0000000000000000
2012/06/06 01:28:57 [debug] 15621#0: *5 finalize http upstream request:
0
2012/06/06 01:28:57 [debug] 15621#0: *5 finalize http proxy request
2012/06/06 01:28:57 [debug] 15621#0: *5 free rr peer 1 0
2012/06/06 01:28:57 [debug] 15621#0: *5 close http upstream connection:
20
2012/06/06 01:28:57 [debug] 15621#0: *5 http upstream temp fd: -1
2012/06/06 01:28:57 [debug] 15621#0: *5 http output filter
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http copy filter:
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http postpone filter
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
00007FFF51B162A0
2012/06/06 01:28:57 [debug] 15621#0: *5 http chunk: 0
2012/06/06 01:28:57 [debug] 15621#0: *5 http write filter: l:1 f:0
s:196
2012/06/06 01:28:57 [debug] 15621#0: *5 http write filter limit 0
2012/06/06 01:28:57 [debug] 15621#0: *5 http write filter
0000000000000000
2012/06/06 01:28:57 [debug] 15621#0: *5 http copy filter: 0
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset"
2012/06/06 01:28:57 [debug] 15621#0: *5 http finalize request: 0,
"/service/home/admin at dev03.test.com/?fmt=tgz&resolve=reset" a:1, c:1
2012/06/06 01:28:57 [debug] 15621#0: *5 set http keepalive handler
2012/06/06 01:28:57 [debug] 15621#0: *5 http close request
2012/06/06 01:28:57 [debug] 15621#0: *5 http log handler
2012/06/06 01:28:57 [debug] 15621#0: *5 hc free: 0000000000000000 0
2012/06/06 01:28:57 [debug] 15621#0: *5 hc busy: 0000000000000000 0
2012/06/06 01:28:57 [debug] 15621#0: *5 tcp_nodelay
2012/06/06 01:28:57 [debug] 15621#0: *5 http keepalive handler
2012/06/06 01:28:57 [debug] 15621#0: *5 http keepalive handler
2012/06/06 01:28:57 [info] 15621#0: *5 client 10.112.117.117 closed
keepalive connection
2012/06/06 01:28:57 [debug] 15621#0: *5 close http connection: 14

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,227175,227182#msg-227182



More information about the nginx mailing list