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

Wed Jul 31 21:54:36 UTC 2013

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!

On Wed, Jul 31, 2013 at 1:01 AM, Maxim Dounin <mdounin at mdounin.ru> wrote:
> Hello!
>
> On Tue, Jul 30, 2013 at 05:21:09PM -0700, Kiran Pillarisetty wrote:
>
>> 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
>> =================
>
> 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 Dounin
> http://nginx.org/en/donation.html
>
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx
-------------- next part --------------
A non-text attachment was scrubbed...
Name: NginxDebugLog-SuccessCaseWith194Kfile.log.zip
Type: application/zip
Size: 6023 bytes
Desc: not available
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20130731/12496c3e/attachment-0002.zip>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: NginxDebugLog-FailureCaseWith196Kfile.log.zip
Type: application/zip
Size: 5575 bytes
Desc: not available
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20130731/12496c3e/attachment-0003.zip>