Hello,

After some research, we simplify our configuration to only have an
header_filter_by_lua_file 'script.lua' with the following
code:

ngx.log(ngx.WARN, string.format("enter script"))
ngx.exit(502)

Making a siege -i -c 100 http://localhost/location we get some of the
reported upstream_response_time.

To verify if this could be some type of concurrency problem we put a
ngx.sleep(0.001) before the ngx.exit() call. Apparently, this change
removed all the wrong times in the upstream_response_time, giving
always the expected value.

Can be this a problem of the lua-nginx-module? Or some nginx race
condition?

Dani

On Wed, 11 Feb 2015 15:26:59 +0000
Maxim Dounin <mdounin@mdounin.ru> wrote:

> Hello!
>
> On Wed, Feb 11, 2015 at 03:20:59PM +0000, Dani Bento wrote:
>
> > Hello,
> >
> > I was looking in ngx_http_upstream_response_time_variable.
> >
> > I understand that if the state[i].status is not 0, the
> > state[i].response_sec is used.
> >
> > It is assumed that if a state doesn't have a peer it prints a ":"
> > before the next state (like the upstream_status_variable)
> >
> > Our problem is that in the log we have:
> >
> > [200 : 302] (for the status codes)
> >
> > [0.02 : 1423667767.600] (for the upstream_response_time)
>
> So the question remains: how this happens.
>
> (Note though, that this can easily happen if you'll try to use the
> $upstream_response_time variable before the request is finalized,
> e.g., in add_header or in 3rd party modules. But it shouldn't
> happen during logging, as the request is expected to be finalized
> at this time.)
>



--
Dani Bento
Direção de Internet e Tecnologia
DTS/DVS
tlm: +351 91 429 72 81
dani@telecom.pt

_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel