[PATCH] Feature: $msec and $start_msec http variables, useful for setting in proxy headers before sending request to backend servers so processing and queue times can be measured.

[Lawrence Pit]

Hello,

Below is a patch based on my own requirements to monitor request and 
queue times within nginx. It's based off stable-1.2 (currently 1.2.5)

$start_msec is the time in milliseconds resolution when the first bytes 
were read from the client.

$msec is the current time in milliseconds resolution.

I use it like this:

server {
   proxy_set_header X-Request-Start $start_msec;
   proxy_set_header X-Queue-Start $msec;
   …
}

I chose the name "msec" as the counterpart of the variable "msec" as 
used by the log formatter.

After I finished this patch I checked the 1.3 branch, and noticed it 
already has an $msec http variable defined. But it's output is with a 
dot character before the milliseconds part. Why is that? I can 
understand why it's formatted like that in a log, but not for use in an 
http variable when it's probably going to be used for calculations.

New Relic has decribed something similar:
https://newrelic.com/docs/features/tracking-front-end-time

Aside: note that New Relic requires the time in microseconds. The only 
way I could find to do this (with my patch) was a workaround using the 
set command. With the 1.3 branch version of $msec there's no way I think 
(or is there?).

server {
   set $usec 000;
   proxy_set_header X-Request-Start 't=$start_msec$usec';
   proxy_set_header X-Queue-Start 't=$msec$usec';
   …
}

It would be nice if proxy_set_header handles strings and interpolation 
in the same way that log_format works, e.g. :

   proxy_set_header X-Something 't=$msec' '000';

But that's for another patch another day. ;p


Cheers,
Lawrence



---
  src/http/ngx_http_variables.c | 60 
+++++++++++++++++++++++++++++++++++++++++++
  1 file changed, 60 insertions(+)

diff --git a/src/http/ngx_http_variables.c 
b/src/http/ngx_http_variables.c
index b0949c7..9cb1330 100644
--- a/src/http/ngx_http_variables.c
+++ b/src/http/ngx_http_variables.c
@@ -108,6 +108,10 @@ static ngx_int_t 
ngx_http_variable_hostname(ngx_http_request_t *r,
      ngx_http_variable_value_t *v, uintptr_t data);
  static ngx_int_t ngx_http_variable_pid(ngx_http_request_t *r,
      ngx_http_variable_value_t *v, uintptr_t data);
+static ngx_int_t ngx_http_variable_msec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data);
+static ngx_int_t ngx_http_variable_start_msec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data);

  /*
   * TODO:
@@ -285,6 +289,12 @@ static ngx_http_variable_t  
ngx_http_core_variables[] = {
      { ngx_string("pid"), NULL, ngx_http_variable_pid,
        0, 0, 0 },

+    { ngx_string("msec"), NULL, ngx_http_variable_msec,
+      0, 0, 0 },
+
+    { ngx_string("start_msec"), NULL, ngx_http_variable_start_msec,
+      0, 0, 0 },
+
  #if (NGX_HAVE_TCP_INFO)
      { ngx_string("tcpinfo_rtt"), NULL, ngx_http_variable_tcpinfo,
        0, NGX_HTTP_VAR_NOCACHEABLE, 0 },
@@ -1915,6 +1925,56 @@ ngx_http_variable_pid(ngx_http_request_t *r,
  }


+static ngx_int_t
+ngx_http_variable_msec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data)
+{
+    u_char           *p;
+    ngx_time_t       *tp;
+    ngx_msec_int_t   ms;
+
+    p = ngx_pnalloc(r->pool, NGX_INT64_LEN);
+    if (p == NULL) {
+        return NGX_ERROR;
+    }
+
+    tp = ngx_timeofday();
+    ms = (ngx_msec_int_t) (tp->sec * 1000 + tp->msec);
+
+    v->len = ngx_sprintf(p, "%L", ms) - p;
+    v->valid = 1;
+    v->no_cacheable = 0;
+    v->not_found = 0;
+    v->data = p;
+
+    return NGX_OK;
+}
+
+
+static ngx_int_t
+ngx_http_variable_start_msec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data)
+{
+    u_char           *p;
+    ngx_msec_int_t   ms;
+
+    p = ngx_pnalloc(r->pool, NGX_INT64_LEN);
+    if (p == NULL) {
+        return NGX_ERROR;
+    }
+
+    ms = (ngx_msec_int_t) (r->start_sec * 1000 + r->start_msec);
+
+    v->len = ngx_sprintf(p, "%L", ms) - p;
+    v->valid = 1;
+    v->no_cacheable = 0;
+    v->not_found = 0;
+    v->data = p;
+
+    return NGX_OK;
+}
+
+
  void *
  ngx_http_map_find(ngx_http_request_t *r, ngx_http_map_t *map, 
ngx_str_t *match)
  {
-- 
1.7.11.1