nginx report a timestamp on upstream_response_time

[Dani Bento]

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)

Dani

On Tue, 10 Feb 2015 18:10:44 +0000
Maxim Dounin <mdounin at mdounin.ru> wrote:

> Hello!
> 
> On Tue, Feb 10, 2015 at 05:51:46PM +0000, Dani Bento wrote:
> 
> [...]
> 
> > But in ngx_http_upstream_init_request we have:
> > 
> > 559     } else {
> > 560 
> > 561         u->state = ngx_array_push(r->upstream_states);
> > 562         if (u->state == NULL) {
> > 563             ngx_http_upstream_finalize_request(r, u,
> > 564
> > NGX_HTTP_INTERNAL_SERVER_ERROR); 565             return;
> > 566         }
> > 567 
> > 568         ngx_memzero(u->state,
> > sizeof(ngx_http_upstream_state_t)); 569     }
> > 
> > The u->state->response_sec and u->state->response_mset are 
> > initialized with ngx_timeofday() in the first case, but are only 
> > zeroed in the second case.
> 
> An empty state added in the ngx_http_upstream_init_request() marks 
> switching to another upstream{} group, to be shown as ":" in the 
> corresponding variables.
> 
> See ngx_http_upstream_response_time_variable() for details.
> 



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