Weird issue between backend and upstream (0 bytes)

[Guzmán Brasó]

By the way, it's getting worse with time....

Total php requests with status 200 since today 6:00 AM:  3708.

Of those, 2292 returned status 200 and received a RST from nginx load
balancer, so more than half of it are getting caught by this issue...

Will try to get the original logs to see if there's some light there...

Thank you!

Guzman

On Thu, Aug 9, 2012 at 4:07 PM, Guzmán Brasó <guzman.braso at gmail.com> wrote:

> Hi Maxim!, once again thank you...
>
> Exactly what I thought.. but something doesn't make sense, the owner of
> the site put some paid traffic on it and I now numbers are bigger than
> before, it could not be that hundreds of people abort the connection
> exactly and precisely at the same byte. It's always the same byte, and it's
> always random thought I've never been able to reproduce it myself. Just
> sniffed others traffic to see it.
>
> Just checked and there's no mention of proxy_ignore_client_abort either on
> frontend (nginx load balancer) or backend (nginx proxy for php-fpm). This
> is really weird....
>
> I think I still have the original debug logs from where that grep came
> from, will check it out as soon I can ssh into it.
>
> Thank you once again!!
>
> Guzmán
>
>
>
>
> On Thu, Aug 9, 2012 at 3:26 PM, Maxim Dounin <mdounin at mdounin.ru> wrote:
>
>> Hello!
>>
>> On Thu, Aug 09, 2012 at 12:10:57PM -0300, Guzmán Brasó wrote:
>>
>> > Hi Maxim! Thanks for taking time to check it out...
>> >
>> > So the 499 seen by the php-fpm nginx here It's not that main nginx
>> closed
>> > the connection but that fastcgi closed the connection?
>> >
>> > All the time thought was nothing to do with the backend... there's no
>> php
>> > warning or error on the php-fpm side when this happens, will try to
>> enable
>> > debug mode in php-fpm and swim around the logs....
>>
>> Ah, sorry, it looks like I've misunderstood what you were trying
>> to say.  Partialy because of strange usage of the "upstream" word -
>> from frontend point of view it's more or less synonym for
>> "backend", you probably mean to say "frontend" instead.
>>
>> Looking though debug log you've provided earlier suggests that
>> everything is actually ok.  Here is quote from frontend logs:
>>
>> > 2012/08/03 13:25:45 [debug] 1546#0: *823 http proxy header done
>> > 2012/08/03 13:25:45 [debug] 1546#0: *823 HTTP/1.1 200 OKM
>> > 2012/08/03 13:25:45 [debug] 1546#0: *823 finalize http upstream
>> request: -1
>> > 2012/08/03 13:25:45 [debug] 1546#0: *823 finalize http proxy request
>>
>> The intresting part is somewhere between "HTTP..." and "finalize
>> ..." lines, but it's at low level and was misssed from grep.  Most
>> likely (assuming request finalization is for reason) client closed
>> request and this resulted in writev() failure.  This in turn
>> caused finalization of a request, and close of the connection to
>> the upstream server (aka backend).  There are 0 bytes sent as
>> nothing was actually sent.  The fact that you see many such log
>> lines suggests that you've probably disabled client abort checks
>> (proxy_ignore_client_abort).
>>
>> On a backend you see this as "200" with some small number of bytes
>> which is some first bytes it was able to send before connection
>> was closed by the frontend.  The 499 finalization is internal, and
>> as response status as sent to client is already 200 - it doesn't
>> affect access log.
>>
>> Maxim Dounin
>>
>> _______________________________________________
>> nginx mailing list
>> nginx at nginx.org
>> http://mailman.nginx.org/mailman/listinfo/nginx
>>
>
>
>
> --
> Guzmán Brasó Núñez
> Senior Perl Developer / Sysadmin
> Web: http://guzman.braso.info
> Mobile: +598 98 674020
>



-- 
Guzmán Brasó Núñez
Senior Perl Developer / Sysadmin
Web: http://guzman.braso.info
Mobile: +598 98 674020
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20120809/f627cbfa/attachment.html>