Only 64k sent when the first upstream failed in fastcgi_pass

[Valentin V. Bartenev]

On Wednesday 18 June 2014 09:46:36 Jing Ye wrote:
> vbart,
> 
> Thanks for the advice, but I’m afraid this is not the case. When i remove
> the 9902 upstream and curl again, it works properly and print 90833 at the
> end with only calling file_get_contents once.
> 
> In addition, in the error.log with debug mode, i found the following lines,
> 
> ………….
> 
> 2014/06/17 21:57:48 [debug] 61130#0: *9 http upstream request: "/index.php?"
> 2014/06/17 21:57:48 [debug] 61130#0: *9 http upstream send request handler
> 2014/06/17 21:57:48 [debug] 61130#0: *9 http upstream send request
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:584
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:32768
> <— here
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:8
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:32768
> <— here
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:8
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:25297
> <— here
> 2014/06/17 21:57:48 [debug] 61130#0: *9 chain writer buf fl:0 s:15
> 
> ………….
> 
> 2014/06/17 21:57:49 [error] 61130#0: *9 upstream prematurely closed
> connection while reading response header from upstream, client: 127.0.0.1,
> server: localhost, request: "PUT /index.php HTTP/1.1", upstream: "fastcgi://
> 127.0.0.1:9902", host: "127.0.0.1:8080”
> …………..
> 
> 2014/06/17 21:57:49 [debug] 61130#0: *9 http next upstream, 2
> 2014/06/17 21:57:49 [debug] 61130#0: *9 http upstream request: "/index.php?"
> 2014/06/17 21:57:49 [debug] 61130#0: *9 http upstream send request handler
> 2014/06/17 21:57:49 [debug] 61130#0: *9 http upstream send request
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:584
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:32768
> <— here
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:8
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:65536
> <— here
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:8
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:90833
> <— here
> 2014/06/17 21:57:49 [debug] 61130#0: *9 chain writer buf fl:0 s:15
> …………..
> 
> Before 9902 failed, the request body was sent correctly in bufs sized
> 32768, 32768 and 25297(totally 90833), but after 9902 failed, the upstream
> module retried sending body with size 32768, 65536 and 90833. Maybe
> something was wrong here.
> 
> I guess after receiving the former 32768 bytes of the second buf(65536),
> php-fpm tries to locate a new fastcgi header but failed, for the data right
> behind is the body data of the image but a pre-constructed fastcgi header.
> So, it mislead php-fpm to think of receiving the data end.
> 
> Refer to the source code, i also found why this happen.
> 
> *https://github.com/nginx/nginx/blob/v1.5.12/src/http/ngx_http_upstream.c#L1441
> <https://github.com/nginx/nginx/blob/v1.5.12/src/http/ngx_http_upstream.c#L1441>*
> 
> In the ngx_http_upstream_reinit function, cl->buf->file_pos are all reset
> to 0 for every buf in the output chain. But i think file_post should be
> reset to 0, 32768, 65536 instead.
> 
> PS: the output chain is initiated here with buf->file_pos = 0, 32768,
> 65536...
> *https://github.com/nginx/nginx/blob/v1.5.12/src/http/modules/ngx_http_fastcgi_module.c#L1085
> <https://github.com/nginx/nginx/blob/v1.5.12/src/http/modules/ngx_http_fastcgi_module.c#L1085>*
> 
> Is this the reason that cause the problem?
[..]

Yes, you're right.  Thank you for the report.

Please, try this patch:

diff -r 25ade23cf281 src/http/modules/ngx_http_fastcgi_module.c
--- a/src/http/modules/ngx_http_fastcgi_module.c        Wed Jun 04 15:09:19 2014 +0400
+++ b/src/http/modules/ngx_http_fastcgi_module.c        Wed Jun 18 18:25:20 2014 +0400
@@ -1126,6 +1126,13 @@ ngx_http_fastcgi_create_request(ngx_http
                     len = (ngx_uint_t) (pos - b->pos);
                 }
 
+                b->shadow = ngx_alloc_buf(r->pool);
+                if (b->shadow == NULL) {
+                    return NGX_ERROR;
+                }
+
+                ngx_memcpy(b->shadow, b, sizeof(ngx_buf_t));
+
                 padding = 8 - len % 8;
                 padding = (padding == 8) ? 0 : padding;
 
diff -r 25ade23cf281 src/http/ngx_http_upstream.c
--- a/src/http/ngx_http_upstream.c      Wed Jun 04 15:09:19 2014 +0400
+++ b/src/http/ngx_http_upstream.c      Wed Jun 18 18:25:20 2014 +0400
@@ -1568,8 +1568,14 @@ ngx_http_upstream_reinit(ngx_http_reques
     /* reinit the request chain */
 
     for (cl = u->request_bufs; cl; cl = cl->next) {
-        cl->buf->pos = cl->buf->start;
-        cl->buf->file_pos = 0;
+
+        if (cl->buf->shadow) {
+            ngx_memcpy(cl->buf, cl->buf->shadow, sizeof(ngx_buf_t));
+
+        } else {
+            cl->buf->pos = cl->buf->start;
+            cl->buf->file_pos = 0;
+        }
     }
 
     /* reinit the subrequest's ngx_output_chain() context */