diff --git a/README.md b/README.md index 08a844e..eb2f62b 100644 --- a/README.md +++ b/README.md @@ -38,6 +38,7 @@ Table of Contents * [$proxy_connect_send_timeout](#proxy_connect_send_timeout-1) * [$proxy_connect_resolve_time](#proxy_connect_resolve_time) * [$proxy_connect_connect_time](#proxy_connect_connect_time) + * [$proxy_connect_first_byte_time](#proxy_connect_first_byte_time) * [$proxy_connect_response](#proxy_connect_response-1) * [Compatibility](#compatibility) * [Nginx Compatibility](#nginx-compatibility) @@ -480,6 +481,15 @@ Keeps time spent on establishing a connection with the upstream server; the time * Value of "-" means name resolving or connecting failed. +$proxy_connect_first_byte_time +--------------------------- + +Keeps time to receive the first byte of data from the upstream server; the time is kept in seconds with millisecond resolution. + +* Value of "" means this module does not work on this request. +* Value of "-" means name resolving, connecting or receving failed. + + $proxy_connect_response --------------------------- diff --git a/ngx_http_proxy_connect_module.c b/ngx_http_proxy_connect_module.c index ca2e924..cb760c1 100644 --- a/ngx_http_proxy_connect_module.c +++ b/ngx_http_proxy_connect_module.c @@ -45,6 +45,7 @@ typedef struct { typedef struct { ngx_msec_t resolve_time; ngx_msec_t connect_time; + ngx_msec_t first_byte_time; /* TODO: off_t bytes_received; @@ -133,6 +134,8 @@ static ngx_int_t ngx_http_proxy_connect_resolve_time_variable(ngx_http_request_t ngx_http_variable_value_t *v, uintptr_t data); static ngx_int_t ngx_http_proxy_connect_connect_time_variable(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data); +static ngx_int_t ngx_http_proxy_connect_first_byte_time_variable(ngx_http_request_t *r, + ngx_http_variable_value_t *v, uintptr_t data); static ngx_int_t ngx_http_proxy_connect_variable_get_response(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data); static void ngx_http_proxy_connect_variable_set_response(ngx_http_request_t *r, @@ -277,6 +280,10 @@ static ngx_http_variable_t ngx_http_proxy_connect_vars[] = { ngx_http_proxy_connect_connect_time_variable, 0, NGX_HTTP_VAR_NOCACHEABLE, 0 }, + { ngx_string("proxy_connect_first_byte_time"), NULL, + ngx_http_proxy_connect_first_byte_time_variable, 0, + NGX_HTTP_VAR_NOCACHEABLE, 0 }, + { ngx_string("proxy_connect_response"), ngx_http_proxy_connect_variable_set_response, ngx_http_proxy_connect_variable_get_response, @@ -722,6 +729,13 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r, do_write = 1; b->last += n; + if (from_upstream) { + if (u->state.first_byte_time == (ngx_msec_t) -1) { + u->state.first_byte_time = ngx_current_msec + - u->start_time; + } + } + continue; } @@ -1042,6 +1056,7 @@ ngx_http_proxy_connect_process_connect(ngx_http_request_t *r, u->start_time = ngx_current_msec; u->state.connect_time = (ngx_msec_t) -1; + u->state.first_byte_time = (ngx_msec_t) -1; rc = ngx_event_connect_peer(&u->peer); @@ -2194,6 +2209,63 @@ ngx_http_proxy_connect_connect_time_variable(ngx_http_request_t *r, } +static ngx_int_t +ngx_http_proxy_connect_first_byte_time_variable(ngx_http_request_t *r, + ngx_http_variable_value_t *v, uintptr_t data) +{ + u_char *p; + size_t len; + ngx_msec_int_t ms; + ngx_http_proxy_connect_ctx_t *ctx; + ngx_http_proxy_connect_upstream_t *u; + + if (r->method != NGX_HTTP_CONNECT) { + return NGX_OK; + } + + v->valid = 1; + v->no_cacheable = 0; + v->not_found = 0; + + ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module); + + if (ctx == NULL) { + v->not_found = 1; + return NGX_OK; + } + + u = ctx->u; + + if (u == NULL || !u->connected) { + v->not_found = 1; + return NGX_OK; + } + + len = NGX_TIME_T_LEN + 4; + + p = ngx_pnalloc(r->pool, len); + if (p == NULL) { + return NGX_ERROR; + } + + v->data = p; + + ms = u->state.first_byte_time; + + if (ms != -1) { + ms = ngx_max(ms, 0); + p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000); + + } else { + *p++ = '-'; + } + + v->len = p - v->data; + + return NGX_OK; +} + + static ngx_int_t ngx_http_proxy_connect_variable_get_response(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data) diff --git a/t/http_proxy_connect_resolve_variables.t b/t/http_proxy_connect_resolve_variables.t index ffe5547..5d5a1ad 100644 --- a/t/http_proxy_connect_resolve_variables.t +++ b/t/http_proxy_connect_resolve_variables.t @@ -78,9 +78,13 @@ events { http { %%TEST_GLOBALS_HTTP%% +# lua_load_resty_core off; + log_format connect '$remote_addr - $remote_user [$time_local] "$request" ' '$status $body_bytes_sent var:$connect_host-$connect_port-$connect_addr ' - 'resolve:$proxy_connect_resolve_time,connect:$proxy_connect_connect_time,'; + 'resolve:$proxy_connect_resolve_time,' + 'connect:$proxy_connect_connect_time,' + 'fbt:$proxy_connect_first_byte_time,'; access_log %%TESTDIR%%/connect.log connect; error_log %%TESTDIR%%/connect_error.log error; @@ -139,6 +143,27 @@ http { access_log off; return 200 "8081 server"; } + + # for $proxy_connect_first_byte_time testing + server { + access_log off; + listen 8082; + rewrite_by_lua ' + ngx.sleep(1) + ngx.say("8082 server fbt") + '; + + } + server { + access_log off; + listen 8083; + rewrite_by_lua ' + ngx.sleep(0.5) + ngx.say("8083 server fbt") + '; + + } + } EOF @@ -197,6 +222,16 @@ like($log, qr/"CONNECT non-existent-domain.com:8081 HTTP\/1.1" 502 .+ resolve:-, $errlog = http_get('/connect_error.log'); like($errlog, qr/proxy_connect: non-existent-domain.com could not be resolved .+Host not found/, 'test error.log for 502 respsone'); +# test first byte time +# fbt:~1s +http_connect_request('127.0.0.1', '8082', '/'); +$log = http_get('/connect.log'); +like($log, qr/"CONNECT 127.0.0.1:8082 HTTP\/1.1" 200 .+ resolve:0\....,connect:0\....,fbt:1\....,/, 'test first byte time: 1s'); +# fbt:~0.5s +http_connect_request('127.0.0.1', '8083', '/'); +$log = http_get('/connect.log'); +like($log, qr/"CONNECT 127.0.0.1:8083 HTTP\/1.1" 200 .+ resolve:0\....,connect:0\....,fbt:0\.5..,/, 'test first byte time: 0.5s'); + $t->stop();