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

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?

Hello!

On Tue, Jul 30, 2013 at 05:21:09PM -0700, Kiran Pillarisetty wrote:

–with-poll_module --with-file-aio --with-http_ssl_module
Everything seems to work fine, except for the file upload. For some reason
are greatly appreciated.
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;

***** Further investigation revealed that we have problem uploading 196K
text/html;charset=utf-8"
Transfer-Encoding: chunked^M
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 write busy: 0
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

From a debug log fragment provided it’s not clear what goes wrong,
you may want to show full debug log.

My best guess is that your backend tries to respond to a request
before it actually read a request. In such a case nginx will stop
sending a request (if there is anything left), but your backend
needs it to complete the response. Hence timeout.

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?

You may try looking into sources to find out.


Maxim D.
http://nginx.org/en/donation.html

Hi Maxim,

Thank you for the response. I am attaching the full debug log files
from success and failure cases.

… In such a case nginx will stopsending a request
(if there is anything left), but your backend
needs it to complete the response. Hence timeout.

In such scenario, how exactly could we prevent Nginx from stopping the
sending of the file?

Also, it is interesting to note that when we access Tomcat port
directly, we can upload the file without an issue.

Thank you!