Welcome! Log In Create A New Profile

Advanced

Re: Only 64k sent when the first upstream failed in fastcgi_pass

Valentin V. Bartenev
June 18, 2014 10:28AM
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 */

_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel
Subject Author Views Posted

Only 64k sent when the first upstream failed in fastcgi_pass

Jing Ye 890 June 17, 2014 11:52AM

Re: Only 64k sent when the first upstream failed in fastcgi_pass

Valentin V. Bartenev 286 June 17, 2014 12:52PM

Re: Only 64k sent when the first upstream failed in fastcgi_pass

Jing Ye 319 June 17, 2014 09:48PM

Re: Only 64k sent when the first upstream failed in fastcgi_pass

Valentin V. Bartenev 522 June 18, 2014 10:28AM

Re: Only 64k sent when the first upstream failed in fastcgi_pass

itpp2012 407 June 27, 2014 06:23AM



Sorry, you do not have permission to post/reply in this forum.

Online Users

Guests: 99
Record Number of Users: 6 on February 13, 2018
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready