File upload issue with Nginx (Reverse proxy+SSL negotiation) and Tomcat

Wed Jul 31 00:21:09 UTC 2013

Configuration:

==========
- Nginx as reverse proxy + SSL negotiation
- Apache Tomcat.

- nginx version: nginx/1.5.2
built by gcc 4.1.2 20080704 (Red Hat 4.1.2-54)
TLS SNI support disabled
configure arguments: --with-rtsig_module --with-select_module
--with-poll_module --with-file-aio --with-http_ssl_module
--with-http_realip_module --with-http_addition_module
--with-http_xslt_module --with-http_image_filter_module
--with-http_geoip_module --with-http_sub_module --with-http_dav_module
--with-http_flv_module --with-http_mp4_module
--with-http_gzip_static_module --with-http_random_index_module --with-mail
--with-mail_ssl_module --with-cpp_test_module --with-pcre --with-libatomic
--with-debug
==========

Everything seems to work fine, except for the file upload. For some reason
file upload never completes. With the configuration listed below, I am able
to upload small files (4K). Upload fails on a 194K file. When I increase
"client_body_buffer_size" to 256K, I can upload the 194K file, but a 500K
file upload fails. Increasing "client_body_buffer_size" beyond 256K has no
impact.

**Note: When I access Tomcat directly and upload the 500K file, it finishes
in a few milliseconds.**

So, looks like something is wrong with Nginx configuration. Any suggestions
are greatly appreciated.

location / {
root /xyz;
proxy_pass http://127.0.0.1:9090;
proxy_redirect off;
proxy_set_header Host $host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-Server $host;
proxy_intercept_errors on;

proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
client_max_body_size 500m;
client_body_buffer_size 128k;
proxy_buffering on;
proxy_connect_timeout 75;
proxy_send_timeout 180;
proxy_read_timeout 180;
proxy_buffer_size 128k;
proxy_buffers 4 256k;
proxy_busy_buffers_size 256k;
proxy_temp_file_write_size 64k;

}

I have tried adding several other parameters to nginx config
(client_body_temp_path, proxy_temp_path, proxy_temp_file_write_size). They
didn't seem to help.

====

***** Further investigation revealed that we have problem uploading 196K
file and upwards. 194K file works. "client_body_buffer_size" value is set
to 256K.

Nginx debug logs show the following in case of failue:
===========
2013/07/30 16:29:57 [debug] 14208#0: *1 recv: fd:11 2606 of 16384
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy status 200 "200 OK"
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy header: "Server:
Apache-Coyote/1.1"
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy header: "Content-Type:
text/html;charset=utf-8"
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy header: "Date: Tue, 30
Jul 2013 22:29:57 GMT"
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy header: "Connection:
close"
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy header done
2013/07/30 16:29:57 [debug] 14208#0: *1 xslt filter header
2013/07/30 16:29:57 [debug] 14208#0: *1 HTTP/1.1 200 OK^M
Server: nginx/1.5.2^M
Date: Tue, 30 Jul 2013 22:29:57 GMT^M
Content-Type: text/html;charset=utf-8^M
Transfer-Encoding: chunked^M
Connection: keep-alive^M

2013/07/30 16:29:57 [debug] 14208#0: *1 write new buf t:1 f:0
000000001E61DAD8, pos 000000001E61DAD8, size: 168 file: 0, size: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 http write filter: l:0 f:0 s:168
2013/07/30 16:29:57 [debug] 14208#0: *1 http cacheable: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 posix_memalign:
000000001E62D450:4096 @16
2013/07/30 16:29:57 [debug] 14208#0: *1 http proxy filter init s:200 h:0
c:0 l:-1
2013/07/30 16:29:57 [debug] 14208#0: *1 http upstream process upstream
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe read upstream: 1
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe preread: 2465
2013/07/30 16:29:57 [debug] 14208#0: *1 readv: 1:13778
2013/07/30 16:29:57 [debug] 14208#0: *1 readv() not ready (11: Resource
temporarily unavailable)
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe recv chain: -2
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe buf free s:0 t:1 f:0
000000001E61DBD0, pos 000000001E61DC5D, size: 2465 file: 0, size: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe length: -1
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe write downstream: 1
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe write busy: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe write: out:0000000000000000,
f:0
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe read upstream: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe buf free s:0 t:1 f:0
000000001E61DBD0, pos 000000001E61DC5D, size: 2465 file: 0, size: 0
2013/07/30 16:29:57 [debug] 14208#0: *1 pipe length: -1
2013/07/30 16:29:57 [debug] 14208#0: *1 event timer add: 11:
180000:1375223577332
2013/07/30 16:29:57 [debug] 14208#0: *1 http upstream request:
"/upload/html?"
2013/07/30 16:29:57 [debug] 14208#0: *1 http upstream send request handler
2013/07/30 16:29:57 [debug] 14208#0: timer delta: 6
2013/07/30 16:29:57 [debug] 14208#0: posted events 0000000000000000
2013/07/30 16:29:57 [debug] 14208#0: worker cycle
2013/07/30 16:29:57 [debug] 14208#0: epoll timer: 179994
=================

I notice "http upstream send request handler" in above log snippet, where
as in success case, I see this:
2013/07/30 16:29:44 [debug] 14208#0: *1 http upstream dummy handler

Any idea what "http upstream send request handler" and "http upstream dummy
handler" mean, and what they signify?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20130730/ed2383bf/attachment.html>