[nginx] Upstream: revised upstream response time variables.

[Vladimir Homutov]

details: http://hg.nginx.org/nginx/rev/860d3907da1c
branches:
changeset: 7397:860d3907da1c
user: Vladimir Homutov <***@nginx.com>
date: Wed Nov 21 13:40:40 2018 +0300
description:
Upstream: revised upstream response time variables.

Variables now do not depend on presence of the HTTP status code in response.
If the corresponding event occurred, variables contain time between request
creation and the event, and "-" otherwise.

Previously, intermediate value of the $upstream_response_time variable held
unix timestamp.

diffstat:

src/http/ngx_http_upstream.c | 40 ++++++++++++++++++-----------------
src/http/ngx_http_upstream.h | 2 +
src/stream/ngx_stream_proxy_module.c | 14 ++++++++----
src/stream/ngx_stream_upstream.c | 16 ++++++--------
src/stream/ngx_stream_upstream.h | 1 +
5 files changed, 40 insertions(+), 33 deletions(-)

diffs (197 lines):

diff -r e8bdd322d7a6 -r 860d3907da1c src/http/ngx_http_upstream.c
--- a/src/http/ngx_http_upstream.c Wed Nov 21 13:40:36 2018 +0300
+++ b/src/http/ngx_http_upstream.c Wed Nov 21 13:40:40 2018 +0300
@@ -1505,8 +1505,8 @@ ngx_http_upstream_connect(ngx_http_reque

r->connection->log->action = "connecting to upstream";

- if (u->state && u->state->response_time) {
- u->state->response_time = ngx_current_msec - u->state->response_time;
+ if (u->state && u->state->response_time == (ngx_msec_t) -1) {
+ u->state->response_time = ngx_current_msec - u->start_time;
}

u->state = ngx_array_push(r->upstream_states);
@@ -1518,7 +1518,9 @@ ngx_http_upstream_connect(ngx_http_reque

ngx_memzero(u->state, sizeof(ngx_http_upstream_state_t));

- u->state->response_time = ngx_current_msec;
+ u->start_time = ngx_current_msec;
+
+ u->state->response_time = (ngx_msec_t) -1;
u->state->connect_time = (ngx_msec_t) -1;
u->state->header_time = (ngx_msec_t) -1;

@@ -2002,7 +2004,7 @@ ngx_http_upstream_send_request(ngx_http_
"http upstream send request");

if (u->state->connect_time == (ngx_msec_t) -1) {
- u->state->connect_time = ngx_current_msec - u->state->response_time;
+ u->state->connect_time = ngx_current_msec - u->start_time;
}

if (!u->request_sent && ngx_http_upstream_test_connect(c) != NGX_OK) {
@@ -2413,7 +2415,7 @@ ngx_http_upstream_process_header(ngx_htt

/* rc == NGX_OK */

- u->state->header_time = ngx_current_msec - u->state->response_time;
+ u->state->header_time = ngx_current_msec - u->start_time;

if (u->headers_in.status_n >= NGX_HTTP_SPECIAL_RESPONSE) {

@@ -4309,8 +4311,8 @@ ngx_http_upstream_finalize_request(ngx_h
u->resolved->ctx = NULL;
}

- if (u->state && u->state->response_time) {
- u->state->response_time = ngx_current_msec - u->state->response_time;
+ if (u->state && u->state->response_time == (ngx_msec_t) -1) {
+ u->state->response_time = ngx_current_msec - u->start_time;

if (u->pipe && u->pipe->read_length) {
u->state->bytes_received += u->pipe->read_length
@@ -5419,18 +5421,18 @@ ngx_http_upstream_response_time_variable
state = r->upstream_states->elts;

for ( ;; ) {
- if (state[i].status) {
-
- if (data == 1 && state[i].header_time != (ngx_msec_t) -1) {
- ms = state[i].header_time;
-
- } else if (data == 2 && state[i].connect_time != (ngx_msec_t) -1) {
- ms = state[i].connect_time;
-
- } else {
- ms = state[i].response_time;
- }
-
+
+ if (data == 1) {
+ ms = state[i].header_time;
+
+ } else if (data == 2) {
+ ms = state[i].connect_time;
+
+ } else {
+ ms = state[i].response_time;
+ }
+
+ if (ms != -1) {
ms = ngx_max(ms, 0);
p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000);

diff -r e8bdd322d7a6 -r 860d3907da1c src/http/ngx_http_upstream.h
--- a/src/http/ngx_http_upstream.h Wed Nov 21 13:40:36 2018 +0300
+++ b/src/http/ngx_http_upstream.h Wed Nov 21 13:40:40 2018 +0300
@@ -365,6 +365,8 @@ struct ngx_http_upstream_s {
ngx_int_t (*rewrite_cookie)(ngx_http_request_t *r,
ngx_table_elt_t *h);

+ ngx_msec_t start_time;
+
ngx_http_upstream_state_t *state;

ngx_str_t method;
diff -r e8bdd322d7a6 -r 860d3907da1c src/stream/ngx_stream_proxy_module.c
--- a/src/stream/ngx_stream_proxy_module.c Wed Nov 21 13:40:36 2018 +0300
+++ b/src/stream/ngx_stream_proxy_module.c Wed Nov 21 13:40:40 2018 +0300
@@ -690,7 +690,7 @@ ngx_stream_proxy_connect(ngx_stream_sess
u->proxy_protocol = pscf->proxy_protocol;

if (u->state) {
- u->state->response_time = ngx_current_msec - u->state->response_time;
+ u->state->response_time = ngx_current_msec - u->start_time;
}

u->state = ngx_array_push(s->upstream_states);
@@ -701,9 +701,11 @@ ngx_stream_proxy_connect(ngx_stream_sess

ngx_memzero(u->state, sizeof(ngx_stream_upstream_state_t));

+ u->start_time = ngx_current_msec;
+
u->state->connect_time = (ngx_msec_t) -1;
u->state->first_byte_time = (ngx_msec_t) -1;
- u->state->response_time = ngx_current_msec;
+ u->state->response_time = (ngx_msec_t) -1;

rc = ngx_event_connect_peer(&u->peer);

@@ -817,7 +819,7 @@ ngx_stream_proxy_init_upstream(ngx_strea
}
}

- u->state->connect_time = ngx_current_msec - u->state->response_time;
+ u->state->connect_time = ngx_current_msec - u->start_time;

if (u->peer.notify) {
u->peer.notify(&u->peer, u->peer.data,
@@ -1622,7 +1624,7 @@ ngx_stream_proxy_process(ngx_stream_sess
if (from_upstream) {
if (u->state->first_byte_time == (ngx_msec_t) -1) {
u->state->first_byte_time = ngx_current_msec
- - u->state->response_time;
+ - u->start_time;
}
}

@@ -1857,7 +1859,9 @@ ngx_stream_proxy_finalize(ngx_stream_ses
pc = u->peer.connection;

if (u->state) {
- u->state->response_time = ngx_current_msec - u->state->response_time;
+ if (u->state->response_time == (ngx_msec_t) -1) {
+ u->state->response_time = ngx_current_msec - u->start_time;
+ }

if (pc) {
u->state->bytes_received = u->received;
diff -r e8bdd322d7a6 -r 860d3907da1c src/stream/ngx_stream_upstream.c
--- a/src/stream/ngx_stream_upstream.c Wed Nov 21 13:40:36 2018 +0300
+++ b/src/stream/ngx_stream_upstream.c Wed Nov 21 13:40:40 2018 +0300
@@ -267,24 +267,22 @@ ngx_stream_upstream_response_time_variab
for ( ;; ) {

if (data == 1) {
- if (state[i].first_byte_time == (ngx_msec_t) -1) {
- *p++ = '-';
- goto next;
- }
-
ms = state[i].first_byte_time;

- } else if (data == 2 && state[i].connect_time != (ngx_msec_t) -1) {
+ } else if (data == 2) {
ms = state[i].connect_time;

} else {
ms = state[i].response_time;
}

- ms = ngx_max(ms, 0);
- p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000);
+ if (ms != -1) {
+ ms = ngx_max(ms, 0);
+ p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000);

- next:
+ } else {
+ *p++ = '-';
+ }

if (++i == s->upstream_states->nelts) {
break;
diff -r e8bdd322d7a6 -r 860d3907da1c src/stream/ngx_stream_upstream.h
--- a/src/stream/ngx_stream_upstream.h Wed Nov 21 13:40:36 2018 +0300
+++ b/src/stream/ngx_stream_upstream.h Wed Nov 21 13:40:40 2018 +0300
@@ -130,6 +130,7 @@ typedef struct {
time_t start_sec;
ngx_uint_t requests;
ngx_uint_t responses;
+ ngx_msec_t start_time;

ngx_str_t ssl_name;