# File upload with a 500 response **URL:** \ **Category:** NGINX\ **Created:** [June 18, 2010, 1:04pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357 "2010-06-18T13:04:48Z")\ **Posts on this page:** 5\ **Page:** 1
**Author:** ![woodsmar](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/f1d935/32.png) [@woodsmar](https://www.ruby-forum.com/u/woodsmar)\ **Post date:** [June 18, 2010, 1:04pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357/1 "2010-06-18T13:04:48Z")
[size=small] Hi I’m seeing some unusual behaviour in one specific client interaction with nginx and wonder if anyone has seen anything similar or can offer any explanation as to why this might be happening. I’m running nginx version 0.7.65. > From a curl command line I’m issuing a POST request to nginx over https. > The POST request has a content-type of multipart/form-data and I’m using > it to send some data and upload a file of just under 1Mb. nginx is being used as a proxy for upstream web servers built with mochiweb. Under normal conditions, everything works fine. The file is uploaded successfully and stored in the back-end database. During testing I’m deliberately causing a 500 Internal Server Error to be returned by the upstream web servers to nginx, and this is where I’m seeing some unusual behaviour. The 500 status code is indeed returned but there is something strange going on with the client/nginx/upstream web server interaction. The whole interaction takes about 10 seconds. Curl rapidly receives the response headers with the 500 status code but then waits. It never receives the response body sent by the client - in this case the content-length is only 200 bytes and the client receives this length in the Content-Length response header. Curl reports an error code 18, meaning that it expected a response body of (in this case) 200 bytes but received less than this (zero in fact as curl reports that the transfer was closed with 200 bytes remaining to read). If I reduce the size of the file uploaded by this method, the problem disappears and curl receives the entire response body just fine. Also, everything is just fine with other web services where I deliberately introduce a 500 response code. It’s just for the file upload of a significantly sized file (about 1Mb) that I see this behaviour. I know that nginx will receive the file in its entirety and store it in a temporary location on the server before it talks to the upstream web server, and it clearly is talking to the upstream web server so it seems it has received the file completely before it attempts to return the 500 code. I’ve also bypassed nginx and let curl talk directly to the upstream web server. In this case, the 500 response is received rapidly and in full (body intact). Here’s the interaction as recorded by Curl: - User-Agent: curl/7.19.5 (i486-pc-linux-gnu) libcurl/7.19.5 OpenSSL/0.9.8g zlib/1.2.3.3 libidn/1.15 - Host: 127.0.0.1 - Accept: _/_ - Content-Length: 775038 - Expect: 100-continue - Content-Type: multipart/form-data; boundary=----------------------------5b3896de4770 - - HTTP/1.1 100 Continue - HTTP/1.1 500 Internal Server Error - Server: nginx/0.7.65 - Date: Fri, 18 Jun 2010 10:31:28 GMT - Content-Type: text/html - Connection: keep-alive - Content-Length: 200 - - SSLv3, TLS alert, Client hello (1): - transfer closed with 200 bytes remaining to read - Closing connection #0 - SSLv3, TLS alert, Client hello (1): curl: (18) transfer closed with 200 bytes remaining to read The nginx logs show that a 500 response code was indeed returned, but the body’s content-length was zero. This isn’t a showstopper, but it’s behaviour I can’t explain. Can anyone offer any ideas as to why I might be seeing this? Thanks! woodsmar [/size] Posted at Nginx Forum: > **[File upload with a 500 response](https://forum.nginx.org/read.php?2,99801,99801#msg-99801)** > > \[size=small\] Hi I'm seeing some unusual behaviour in one specific client interaction with nginx and wonder if anyone has seen anything similar or can offer any explanation as to why this might be happening. I'm running nginx version 0.7.65. From a... ---
**Author:** ![woodsmar](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/f1d935/32.png) [@woodsmar](https://www.ruby-forum.com/u/woodsmar)\ **Post date:** [June 18, 2010, 2:02pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357/2 "2010-06-18T14:02:11Z")
Hello! On Fri, Jun 18, 2010 at 07:04:07AM -0400, woodsmar wrote: > mochiweb. Under normal conditions, everything works fine. The file is > content-length is only 200 bytes and the client receives this length in > the Content-Length response header. Curl reports an error code 18, > meaning that it expected a response body of (in this case) 200 bytes but > received less than this (zero in fact as curl reports that the transfer > was closed with 200 bytes remaining to read). > > If I reduce the size of the file uploaded by this method, the problem > disappears and curl receives the entire response body just fine. Also, > everything is just fine with other web services where I deliberately > introduce a 500 response code. It’s just for the file upload of a > significantly sized file (about 1Mb) that I see this behaviour. Please produce debug log. See here for details: > **[GitHub - nginxinc/nginx-wiki: ARCHIVED -- Source for the now archived NGINX Wiki...](https://github.com/nginxinc/nginx-wiki)** > > ARCHIVED -- Source for the now archived NGINX Wiki section of https://www.nginx.com If I’m right in my assumption that your backend returns 500 before actually reading request body - the following patch may help: diff --git a/src/http/ngx\_http\_upstream.c b/src/http/ngx\_http\_upstream.c — a/src/http/ngx\_http\_upstream.c +++ b/src/http/ngx\_http\_upstream.c @@ -2003,10 +2003,12 @@ ngx\_http\_upstream\_send\_response(ngx\_http ``` u->header_sent = 1; ``` +#if 0 if (r-\>request\_body && r-\>request\_body-\>temp\_file) { ngx\_pool\_run\_cleanup\_file(r-\>pool, r-\>request\_body-\>temp\_file-\>file.fd); r-\>request\_body-\>temp\_file-\>file.fd = NGX\_INVALID\_FILE; } +#endif ``` clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module); ``` Maxim D. ---
**Author:** ![woodsmar](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/f1d935/32.png) [@woodsmar](https://www.ruby-forum.com/u/woodsmar)\ **Post date:** [June 18, 2010, 4:25pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357/3 "2010-06-18T16:25:36Z")
[size=small] Hi Maxim Many thanks for your excellent suggestion! I tried the patch but unfortunately that didn’t work as I still get the same behaviour. With debugging turned on the following is an excerpt from the error log: 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy status 500 “500 Internal Server Error” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy header: “Server: MochiWeb/1.1” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy header: “Date: Fri, 18 Jun 2010 12:16:48 GMT” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy header: “Content-Type: text/html” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy header: “Content-Length: 272” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http proxy header done 2010/06/18 13:16:48 [debug] 30676#0: \*1 HTTP/1.1 500 Internal Server Error Server: nginx/0.7.65 Date: Fri, 18 Jun 2010 12:16:48 GMT Content-Type: text/html Connection: keep-alive Content-Length: 272 2010/06/18 13:16:48 [debug] 30676#0: \*1 write new buf t:1 f:0 08DAB75C, pos 08DAB75C, size: 167 file: 0, size: 0 2010/06/18 13:16:48 [debug] 30676#0: \*1 http write filter: l:0 f:0 s:167 2010/06/18 13:16:48 [debug] 30676#0: \*1 file cleanup: fd:12 2010/06/18 13:16:48 [debug] 30676#0: \*1 http cacheable: 0 2010/06/18 13:16:48 [debug] 30676#0: \*1 http upstream process upstream 2010/06/18 13:16:48 [debug] 30676#0: \*1 pipe read upstream: 1 2010/06/18 13:16:48 [debug] 30676#0: \*1 pipe preread: 272 2010/06/18 13:16:48 [debug] 30676#0: \*1 readv: 1:3642 2010/06/18 13:16:48 [error] 30676#0: \*1 readv() failed (104: Connection reset by peer) while reading upstream, client: 1 27.0.0.1, server: [myserver.com](http://myserver.com), request: “POST /some/url HTTP/1.1”, upstream: “[http://some/other/url](http://some/other/url)”, host: “127.0.0.1” 2010/06/18 13:16:48 [debug] 30676#0: \*1 pipe recv chain: -1 2010/06/18 13:16:48 [debug] 30676#0: \*1 pipe write downstream: 1 2010/06/18 13:16:48 [debug] 30676#0: \*1 pipe write downstream done 2010/06/18 13:16:48 [debug] 30676#0: \*1 event timer add: 13: 60000:1258182058 2010/06/18 13:16:48 [debug] 30676#0: \*1 http upstream exit: 00000000 2010/06/18 13:16:48 [debug] 30676#0: \*1 finalize http upstream request: 0 2010/06/18 13:16:48 [debug] 30676#0: \*1 finalize http proxy request 2010/06/18 13:16:48 [debug] 30676#0: \*1 free rr peer 2 0 2010/06/18 13:16:48 [debug] 30676#0: \*1 close http upstream connection: 13 2010/06/18 13:16:48 [debug] 30676#0: \*1 event timer del: 13: 1258182058 2010/06/18 13:16:48 [debug] 30676#0: \*1 event timer del: 13: 1258181956 2010/06/18 13:16:48 [debug] 30676#0: \*1 http upstream temp fd: -1 2010/06/18 13:16:48 [debug] 30676#0: \*1 http output filter “/some/url” 2010/06/18 13:16:48 [debug] 30676#0: \*1 copy filter: “/some/url” 2010/06/18 13:16:48 [debug] 30676#0: \*1 http postpone filter “/some/url” BFAB4798 2010/06/18 13:16:48 [debug] 30676#0: \*1 write old buf t:1 f:0 08DAB75C, pos 08DAB75C, size: 167 file: 0, size: 0 2010/06/18 13:16:48 [debug] 30676#0: \*1 write new buf t:0 f:0 00000000, pos 00000000, size: 0 file: 0, size: 0 There is in fact an error in there - “readv() failed (104: Connection reset by peer)”. So is this the upstream server closing the connection before it received the entire body, because it already responded? [/size] Posted at Nginx Forum: > **[Re: File upload with a 500 response](https://forum.nginx.org/read.php?2,99801,99902#msg-99902)** > > \[size=small\] Hi I'm seeing some unusual behaviour in one specific client interaction with nginx and wonder if anyone has seen anything similar or can offer any explanation as to why this might be happening. I'm running nginx version 0.7.65. From a... ---
**Author:** ![woodsmar](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/f1d935/32.png) [@woodsmar](https://www.ruby-forum.com/u/woodsmar)\ **Post date:** [June 21, 2010, 2:09pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357/4 "2010-06-21T14:09:59Z")
Hello! On Fri, Jun 18, 2010 at 10:25:10AM -0400, woodsmar wrote: > I tried the patch but unfortunately that didn’t work as I still get the > same behaviour. With debugging turned on the following is an excerpt > from the error log: […] > 2010/06/18 13:16:48 [debug] 30676#0: \*1 readv: 1:3642 > 2010/06/18 13:16:48 [error] 30676#0: \*1 readv() failed (104: Connection > reset by peer) while reading upstream, client: 1 > 27.0.0.1, server: [myserver.com](http://myserver.com), request: “POST /some/url HTTP/1.1”, > upstream: “[http://some/other/url](http://some/other/url)”, host: “127.0.0.1” Backend reseted connection instead of closing it, that’s the reason why you don’t see reply. In your particular case nginx actually got full reply but discarded body as it got error from backend before it was able to send it. This theoretically may be handled gracefully (and I even posted patches for this a while ago). But note that with reset there is a good chance that nginx won’t see data at all as they will be discarded in socket buffer by OS. Maxim D. ---
**Author:** ![woodsmar](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/f1d935/32.png) [@woodsmar](https://www.ruby-forum.com/u/woodsmar)\ **Post date:** [June 21, 2010, 2:24pm UTC](https://www.ruby-forum.com/t/file-upload-with-a-500-response/190357/5 "2010-06-21T14:24:37Z")
[size=small] Ah, I see…That makes a lot of sense! Many thanks again, Maxim. Your help has been really really useful! Now I’ll turn my attention to the backend… Kind regards, woodsmar [/size] Posted at Nginx Forum: > **[Re: File upload with a 500 response](https://forum.nginx.org/read.php?2,99801,100788#msg-100788)** > > \[size=small\] Hi I'm seeing some unusual behaviour in one specific client interaction with nginx and wonder if anyone has seen anything similar or can offer any explanation as to why this might be happening. I'm running nginx version 0.7.65. From a...