changeset 7397:860d3907da1c

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.
author Vladimir Homutov <vl@nginx.com>
date Wed, 21 Nov 2018 13:40:40 +0300
parents e8bdd322d7a6
children bca4dad0d3cb
files src/http/ngx_http_upstream.c src/http/ngx_http_upstream.h src/stream/ngx_stream_proxy_module.c src/stream/ngx_stream_upstream.c src/stream/ngx_stream_upstream.h
diffstat 5 files changed, 40 insertions(+), 33 deletions(-) [+]
line wrap: on
line diff
--- 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 @@
 
     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_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 @@
                    "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 @@
 
     /* 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 @@
         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 @@
     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);
 
--- 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 @@
     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;
--- 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 @@
     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_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 @@
         }
     }
 
-    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 @@
                 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 @@
     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;
--- 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 @@
     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;
--- 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 @@
     time_t                             start_sec;
     ngx_uint_t                         requests;
     ngx_uint_t                         responses;
+    ngx_msec_t                         start_time;
 
     ngx_str_t                          ssl_name;