From 5768a6824d2126dcb1008ba139a30bd660660cf6 Mon Sep 17 00:00:00 2001 From: "agentzh (Yichun Zhang)" Date: Thu, 6 Dec 2012 18:15:41 -0800 Subject: [PATCH] feature: added ngx.req.start_time() to return the request starting time in seconds (the milliseconds part is the decimal part just as in ngx.now). thanks Matthieu Tourne for the patch. --- README | 12 +++++ README.markdown | 13 +++++ doc/HttpLuaModule.wiki | 12 +++++ src/ngx_http_lua_time.c | 31 ++++++++++- src/ngx_http_lua_time.h | 2 +- src/ngx_http_lua_util.c | 9 +--- t/062-count.t | 6 +-- t/102-req-start-time.t | 117 ++++++++++++++++++++++++++++++++++++++++ 8 files changed, 190 insertions(+), 12 deletions(-) create mode 100644 t/102-req-start-time.t diff --git a/README b/README index 6c2ace93..2ab396b7 100644 --- a/README +++ b/README @@ -3472,6 +3472,18 @@ Nginx API for Lua ... end + ngx.req.start_time + syntax: *secs = ngx.req.start_time()* + + context: *set_by_lua*, rewrite_by_lua*, access_by_lua*, content_by_lua*, + header_filter_by_lua*, body_filter_by_lua*, log_by_lua** + + Returns a floating-point number representing the timestamp (including + milliseconds as the decimal part) when the current request was created. + + The following example is similar to $request_time in Nginx log module : + local request_time = ngx.now() - ngx.req.start_time() + ngx.is_subrequest syntax: *value = ngx.is_subrequest* diff --git a/README.markdown b/README.markdown index 5fad6b0f..b51fde97 100644 --- a/README.markdown +++ b/README.markdown @@ -3196,6 +3196,19 @@ Parse the http time string (as returned by [ngx.http_time](http://wiki.nginx.org end +ngx.req.start_time +------------------ +**syntax:** *secs = ngx.req.start_time()* + +**context:** *set_by_lua*, rewrite_by_lua*, access_by_lua*, content_by_lua*, header_filter_by_lua*, body_filter_by_lua*, log_by_lua** + +Returns a floating-point number representing the timestamp (including milliseconds as the decimal part) when the current request was created. + +The following example is similar to $request_time in Nginx log module : + + local request_time = ngx.now() - ngx.req.start_time() + + ngx.is_subrequest ----------------- **syntax:** *value = ngx.is_subrequest* diff --git a/doc/HttpLuaModule.wiki b/doc/HttpLuaModule.wiki index 90901861..02bc0450 100644 --- a/doc/HttpLuaModule.wiki +++ b/doc/HttpLuaModule.wiki @@ -3086,6 +3086,18 @@ Parse the http time string (as returned by [[#ngx.http_time|ngx.http_time]]) int end +== ngx.req.start_time == +'''syntax:''' ''secs = ngx.req.start_time()'' + +'''context:''' ''set_by_lua*, rewrite_by_lua*, access_by_lua*, content_by_lua*, header_filter_by_lua*, body_filter_by_lua*, log_by_lua*'' + +Returns a floating-point number representing the timestamp (including milliseconds as the decimal part) when the current request was created. + +The following example is similar to $request_time in Nginx log module : + + local request_time = ngx.now() - ngx.req.start_time() + + == ngx.is_subrequest == '''syntax:''' ''value = ngx.is_subrequest'' diff --git a/src/ngx_http_lua_time.c b/src/ngx_http_lua_time.c index 9997166b..e6522597 100644 --- a/src/ngx_http_lua_time.c +++ b/src/ngx_http_lua_time.c @@ -4,6 +4,7 @@ #include "ddebug.h" #include "ngx_http_lua_time.h" +#include "ngx_http_lua_util.h" static int ngx_http_lua_ngx_today(lua_State *L); @@ -15,6 +16,7 @@ static int ngx_http_lua_ngx_cookie_time(lua_State *L); static int ngx_http_lua_ngx_http_time(lua_State *L); static int ngx_http_lua_ngx_parse_http_time(lua_State *L); static int ngx_http_lua_ngx_update_time(lua_State *L); +static int ngx_http_lua_ngx_req_start_time(lua_State *L); static int @@ -175,6 +177,25 @@ ngx_http_lua_ngx_parse_http_time(lua_State *L) } +static int +ngx_http_lua_ngx_req_start_time(lua_State *L) +{ + ngx_http_request_t *r; + + lua_pushlightuserdata(L, &ngx_http_lua_request_key); + lua_rawget(L, LUA_GLOBALSINDEX); + r = lua_touserdata(L, -1); + lua_pop(L, 1); + + if (r == NULL) { + return luaL_error(L, "no request found"); + } + + lua_pushnumber(L, (lua_Number) (r->start_sec + r->start_msec / 1000.0L)); + return 1; +} + + void ngx_http_lua_inject_time_api(lua_State *L) { @@ -211,7 +232,15 @@ ngx_http_lua_inject_time_api(lua_State *L) lua_pushcfunction(L, ngx_http_lua_ngx_http_time); lua_setfield(L, -2, "http_time"); - lua_pushcfunction(L, ngx_http_lua_ngx_parse_http_time); + lua_pushcfunction(L, ngx_http_lua_ngx_parse_http_time); lua_setfield(L, -2, "parse_http_time"); } + +void +ngx_http_lua_inject_req_time_api(lua_State *L) +{ + lua_pushcfunction(L, ngx_http_lua_ngx_req_start_time); + lua_setfield(L, -2, "start_time"); +} + diff --git a/src/ngx_http_lua_time.h b/src/ngx_http_lua_time.h index 2ed53868..db43d139 100644 --- a/src/ngx_http_lua_time.h +++ b/src/ngx_http_lua_time.h @@ -6,7 +6,7 @@ void ngx_http_lua_inject_time_api(lua_State *L); +void ngx_http_lua_inject_req_time_api(lua_State *L); #endif /* NGX_HTTP_LUA_TIME_H */ - diff --git a/src/ngx_http_lua_util.c b/src/ngx_http_lua_util.c index 0eb253bd..a5510217 100644 --- a/src/ngx_http_lua_util.c +++ b/src/ngx_http_lua_util.c @@ -1999,19 +1999,15 @@ ngx_http_lua_inject_req_api(ngx_log_t *log, lua_State *L) { /* ngx.req table */ - lua_createtable(L, 0 /* narr */, 20 /* nrec */); /* .req */ + lua_createtable(L, 0 /* narr */, 21 /* nrec */); /* .req */ ngx_http_lua_inject_req_header_api(log, L); - ngx_http_lua_inject_req_uri_api(log, L); - ngx_http_lua_inject_req_args_api(L); - ngx_http_lua_inject_req_body_api(L); - ngx_http_lua_inject_req_socket_api(L); - ngx_http_lua_inject_req_method_api(L); + ngx_http_lua_inject_req_time_api(L); lua_setfield(L, -2, "req"); } @@ -3271,4 +3267,3 @@ ngx_http_lua_test_expect(ngx_http_request_t *r) return NGX_ERROR; } - diff --git a/t/062-count.t b/t/062-count.t index 53a64c9c..a5dbb202 100644 --- a/t/062-count.t +++ b/t/062-count.t @@ -124,7 +124,7 @@ n = 1 --- request GET /test --- response_body -n = 20 +n = 21 --- no_error_log [error] @@ -146,7 +146,7 @@ n = 20 --- request GET /test --- response_body -n = 20 +n = 21 --- no_error_log [error] @@ -173,7 +173,7 @@ n = 20 --- request GET /test --- response_body -n = 20 +n = 21 --- no_error_log [error] diff --git a/t/102-req-start-time.t b/t/102-req-start-time.t new file mode 100644 index 00000000..8f3110ba --- /dev/null +++ b/t/102-req-start-time.t @@ -0,0 +1,117 @@ +# -*- mode: conf -*- +# vim:set ft= ts=4 sw=4 et fdm=marker: + +use lib 'lib'; +use Test::Nginx::Socket; + +#worker_connections(1014); +#master_process_enabled(1); +log_level('warn'); + +repeat_each(2); + +plan tests => repeat_each() * (blocks() * 3); + +#no_diff(); +no_long_string(); +run_tests(); + +__DATA__ + +=== TEST 1: start time +--- config + location = /start { + content_by_lua 'ngx.say(ngx.req.start_time())'; + } +--- request +GET /start +--- response_body_like: ^\d{10,}(\.\d+)?$ +--- no_error_log +[error] + + + +=== TEST 2: start time in set_by_lua +--- config + location = /start { + set_by_lua $a 'return ngx.req.start_time()'; + echo $a; + } +--- request +GET /start +--- response_body_like: ^\d{10,}(\.\d+)?$ +--- no_error_log +[error] + + + +=== TEST 3: request time +--- config + location = /req_time { + content_by_lua ' + ngx.sleep(0.1) + + local req_time = ngx.now() - ngx.req.start_time() + + ngx.say(req_time) + ngx.say(ngx.req.start_time() < ngx.now()) + '; + } +--- request +GET /req_time +--- response_body_like chop +^(?:0\.[12]|0\.099)\d* +true$ +--- no_error_log +[error] + + + +=== TEST 4: request time update +--- config + location = /req_time { + content_by_lua ' + ngx.sleep(0.1) + + local req_time = ngx.now() - ngx.req.start_time() + + ngx.sleep(0.1) + + ngx.update_time() + + local req_time_updated = ngx.now() - ngx.req.start_time() + + ngx.say(req_time) + ngx.say(req_time_updated) + ngx.say(req_time_updated > req_time) + '; + } +--- request +GET /req_time +--- response_body_like chomp +^(?:0\.[12]|0\.099)\d* +0\.\d+ +true$ +--- no_error_log +[error] + + + +=== TEST 5: init_by_lua +--- http_config + init_by_lua ' + time = ngx.req.start_time() + '; +--- config + location = /t { + content_by_lua ' + ngx.say(time) + '; + } +--- request + GET /t +--- response_body +--- no_error_log +[error] +--- SKIP +