Only 64k sent when the first upstream failed in fastcgi_pass

Jing Ye yejingx at gmail.com
Wed Jun 18 01:46:36 UTC 2014


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?




> Date: Tue, 17 Jun 2014 20:50:13 +0400
> From: "Valentin V. Bartenev" <vbart at nginx.com>
> To: nginx-devel at nginx.org
> Subject: Re: Only 64k sent when the first upstream failed in
>         fastcgi_pass
> Message-ID: <1532980.8VxNd81dtW at vbart-workstation>
> Content-Type: text/plain; charset="utf-8"
> On Tuesday 17 June 2014 23:50:19 Jing Ye wrote:
> > Hello all,
> >
> > I have encountered the following possible bug in Nginx when using the
> > fastcgi_pass directive to put a file larger than 64k. I?m not sure if
> this
> > is a bug or I missed something in the config file.
> >
> > My nginx version is 1.5.12, and the problem remains when i switched to
> the
> > newest 1.7.2.
> >
> >
> > Here is my nginx.conf file,
> >
> >     upstream *api.php.com <http://api.php.com>* {
> >             server 127.0.0.1:9902 max_fails=3 fail_timeout=30s;
> >             server 127.0.0.1:9901 max_fails=3 fail_timeout=30s;
> >     }
> >     server {
> >         listen       8080;
> >         server_name  localhost;
> >         location ~ \.php$ {
> >             root           html;
> >             fastcgi_pass   *api.php.com <http://api.php.com>*;
> >             fastcgi_param  SCRIPT_FILENAME
> > /usr/local/nginx/html/$fastcgi_script_name;
> >             fastcgi_index  index.php;
> >             include        fastcgi_params;
> >         }
> >
> >
> >
> > And the index.php file,
> >
> > <?php
> > /* simplify get the request body and print its length. */
> > $raw_post_data = file_get_contents('php://input', 'r');
> > print(strlen($raw_post_data));
> > sleep(3);               /* waiting for the server to be reset after 1
> > second  */
> > ?>
> >
> >
> [..]
> >
> > The response status is 200 OK, but only 65536 bytes(64k) received.
> > Is this a bug or have i made something wrong in the config file?
> > I?m really confusing and hope if someone could help me figure it out.
> >
> In the FastCGI protocol the data is transferred using "records".  The
> maximum
> size of one record is 64k.  So you're probably getting only the first
> record
> by calling file_get_contents() once.
>   wbr, Valentin V. Bartenev
>
>
> On Tue, Jun 17, 2014 at 11:50 PM, Jing Ye <yejingx at gmail.com> wrote:
> Hello all,
> I have encountered the following possible bug in Nginx when using the
> fastcgi_pass directive to put a file larger than 64k. I’m not sure if this
> is a bug or I missed something in the config file.
> My nginx version is 1.5.12, and the problem remains when i switched to the
> newest 1.7.2.
>
> Here is my nginx.conf file,
>             server 127.0.0.1:9902 max_fails=3 fail_timeout=30s;
>             server 127.0.0.1:9901 max_fails=3 fail_timeout=30s;
>     }
>     server {
>         listen       8080;
>         server_name  localhost;
>         location ~ \.php$ {
>             root           html;
>             fastcgi_pass   *api.php.com <http://api.php.com>*;
>             fastcgi_param  SCRIPT_FILENAME
> /usr/local/nginx/html/$fastcgi_script_name;
>             fastcgi_index  index.php;
>             include        fastcgi_params;
>         }
>
> And the index.php file,
> /* simplify get the request body and print its length. */
> $raw_post_data = file_get_contents('php://input', 'r');
> print(strlen($raw_post_data));
> sleep(3);               /* waiting for the server to be reset after 1
> second  */
> ?>
> We need two php-fpm servers listen on port 9901 and 9902, and importantly,
> the server listen on 9902 should be somehow reset to make the upstream
> module choose the next server listen on 9901. I made this by setting the
> request_terminate_timeout argument to 1s.
>
>
> Send a put request, test.png is a file sized 90833 bytes(>64K)
> * About to connect() to 127.0.0.1 port 8080 (#0)
> *   Trying 127.0.0.1...
> * Adding handle: conn: 0x7fda7b803a00
> * Adding handle: send: 0
> * Adding handle: recv: 0
> * Curl_addHandleToPipeline: length: 1
> * - Conn 0 (0x7fda7b803a00) send_pipe: 1, recv_pipe: 0
> * Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
> > PUT /index.php HTTP/1.1
> > User-Agent: curl/7.30.0
> > Host: 127.0.0.1:8080
> > Accept: */*
> > Content-Length: 90833
> > Expect: 100-continue
> >
> < HTTP/1.1 100 Continue
> * We are completely uploaded and fine
> < HTTP/1.1 200 OK
> * Server nginx/1.5.12 is not blacklisted
> < Server: nginx/1.5.12
> < Date: Tue, 17 Jun 2014 13:55:30 GMT
> < Content-Type: text/html
> < Transfer-Encoding: chunked
> < Connection: keep-alive
> < X-Powered-By: PHP/5.4.24
> <
> * Connection #0 to host 127.0.0.1 left intact
> 65536%
> The response status is 200 OK, but only 65536 bytes(64k) received.
> Is this a bug or have i made something wrong in the config file?
> I’m really confusing and hope if someone could help me figure it out.
>
> Many thanks!
>
      upstream *api.php.com <http://api.php.com>* {
>
>  <?php
>
>  $ curl -T test.png *http://127.0.0.1:8080/index.php
> <http://127.0.0.1:8080/index.php>* -v
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-devel/attachments/20140618/124d6d3d/attachment-0001.html>


More information about the nginx-devel mailing list