Only 64k sent when the first upstream failed in fastcgi_pass

[Jing Ye]

Yes, It works. Thank you for the patch.


On Wed, Jun 18, 2014 at 10:27 PM, Valentin V. Bartenev <vbart at nginx.com>
wrote:

> 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 */
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-devel/attachments/20140619/538ceb1e/attachment.html>