Weird issue between backend and upstream (0 bytes)

[Maxim Dounin]

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