Add a 'start_time' variable to nginx 0.8.33 to support an X-REQUEST-START header. This header is used by New Relic RPM to record queue time.

request_start_variable.patch

--- src/http/ngx_http_variables.c.orig  2010-01-11 03:21:46.000000000 -0800
+++ src/http/ngx_http_variables.c       2010-02-18 10:01:32.000000000 -0800
@@ -93,6 +93,9 @@
 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_start_time(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data);
+
 /*
  * TODO:
  *     Apache CGI: AUTH_TYPE, PATH_INFO (null), PATH_TRANSLATED
@@ -253,6 +256,9 @@
     { ngx_string("pid"), NULL, ngx_http_variable_pid,
       0, 0, 0 },
 
+    { ngx_string("start_time"), NULL, ngx_http_variable_start_time,
+      0, 0, 0 },
+
     { ngx_null_string, NULL, NULL, 0, 0, 0 }
 };
 
@@ -1749,6 +1755,27 @@
     return re;
 }
 
+static ngx_int_t
+ngx_http_variable_start_time(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data)
+{
+    u_char  *p;
+
+    p = ngx_pnalloc(r->pool, NGX_INT64_LEN);
+    if (p == NULL) {
+        return NGX_ERROR;
+    }
+
+    uint64_t usec = (((uint64_t)r->start_sec * 1000 * 1000) + ((uint64_t)r->start_msec * 1000));
+
+    v->len = ngx_sprintf(p, "%L", usec) - p;
+    v->valid = 1;
+    v->no_cacheable = 0;
+    v->not_found = 0;
+    v->data = p;
+
+    return NGX_OK;
+}
 
 ngx_int_t
 ngx_http_regex_exec(ngx_http_request_t *r, ngx_http_regex_t *re, ngx_str_t *s)

NewRelic writes: "To collect request queuing time, you need to mark the HTTP request with a timestamp when queuing starts." -- Given that they are linking to this patch they seem to think this patch does just that. Seems clear enough to me.

Whether this patch really does that....? I wouldn't trust any clarification from an "authoritative source" ;-) Better test for yourself, apply this patch, upload a large file, and see which timestamp you receive in your backend.

Perhaps you could look at it this way: it's the timestamp of the moment nginx adds the proxy header. Nginx probably won't do that when the connection is accept()ed or when the first byte is received, as there's nothing to add the header to yet. Given you probably use proxy_pass, nginx documents: "the entire client request will be buffered in nginx before being passed on to the backend proxied servers". My guess is the timestamp is close to the time the request is passed into the queue for delivery to a backend proxy server.

... but then... ;) if I look at this patch, it appears to me it's sending the recorded start time of the nginx request, i.e. the time when the connection was accept()ed.

The patch below applies to the nginx stable-1.2 branch. It supports two http variables: $usec and $start_usec. In your nginx.conf file you could add:

  proxy_set_header X-Request-Start 't=$start_usec';
  proxy_set_header X-Queue-Start 't=$usec';

Request-Start has the time with a microseconds resolution that indicates when the first bytes were read from the client.

Queue-Start has the time with a microseconds resolution that indicates when the request is sent to the backend server.

I chose the name usec as it seems to be in line with the variable msec as used by the nginx log format variables.

Note that at the New Relic site they indicate they support these two variables, see the paragraph "Implementation Notes" at https://newrelic.com/docs/features/tracking-front-end-time.

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


---
 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..b9a630a 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_usec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data);
+static ngx_int_t ngx_http_variable_start_usec(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("usec"), NULL, ngx_http_variable_usec,
+      0, 0, 0 },
+
+    { ngx_string("start_usec"), NULL, ngx_http_variable_start_usec,
+      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_usec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data)
+{
+    u_char     *p;
+    ngx_time_t *tp;
+    uint64_t   usec;
+
+    p = ngx_pnalloc(r->pool, NGX_INT64_LEN);
+    if (p == NULL) {
+        return NGX_ERROR;
+    }
+
+    tp = ngx_timeofday();
+    usec = (uint64_t) (tp->sec * 1000 * 1000 + tp->msec * 1000);
+
+    v->len = ngx_sprintf(p, "%L", usec) - 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_usec(ngx_http_request_t *r,
+    ngx_http_variable_value_t *v, uintptr_t data)
+{
+    u_char   *p;
+    uint64_t start_usec;
+
+    p = ngx_pnalloc(r->pool, NGX_INT64_LEN);
+    if (p == NULL) {
+        return NGX_ERROR;
+    }
+
+    start_usec = (uint64_t) (r->start_sec * 1000 * 1000 + r->start_msec * 1000);
+
+    v->len = ngx_sprintf(p, "%L", start_usec) - 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