Weird issue between backend and upstream (0 bytes)

[Maxim Dounin]

Hello!

On Thu, Aug 09, 2012 at 04:07:28PM -0300, Guzmán Brasó 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.

As frontend's nginx detects connection abort only when it tries to 
send first bytes of a response, and from logs you've provided it 
looks like response generation takes more than 10 seconds, - it's 
highly unlikely that the abort really happens just before first 
byte.  Most likely it happens during 10 seconds in question.

> 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....

Not really.  There are number of cases which might prevent nginx 
from detecting connection abort by a client, even if it's not 
specifically configured to ignore connection aborts.  Well-known 
cases include connection close with pending pipelined request in a 
connection, or clean connection close of a ssl connection (with 
shutdown alert sent by a client).  In such cases nginx will be 
able to detect connection close only if event method might provide 
some hint about pending connection close (kqueue only as of now).

Maxim Dounin

> 
> 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

> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx