Skip to content

Commit 428b12c

Browse files
chobitschobits
committed
Added variables for debugging: $proxy_connect_resolve_time and $proxy_connect_connect_time
Try to resolve issue: chobits#144
1 parent 52599d8 commit 428b12c

File tree

3 files changed

+561
-10
lines changed

3 files changed

+561
-10
lines changed

‎README.md‎

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,8 @@ Table of Contents
3535
* [$proxy_connect_connect_timeout](#proxy_connect_connect_timeout-1)
3636
* [$proxy_connect_read_timeout](#proxy_connect_read_timeout-1)
3737
* [$proxy_connect_send_timeout](#proxy_connect_send_timeout-1)
38+
* [$proxy_connect_resolve_time](#proxy_connect_resolve_time)
39+
* [$proxy_connect_connect_time](#proxy_connect_connect_time)
3840
* [Compatibility](#compatibility)
3941
* [Nginx Compatibility](#nginx-compatibility)
4042
* [OpenResty Compatibility](#openresty-compatibility)
@@ -413,6 +415,23 @@ $proxy_connect_send_timeout
413415

414416
Get or set a timeout of [`proxy_connect_send_timeout` directive](#proxy_connect_send_timeout).
415417

418+
$proxy_connect_resolve_time
419+
---------------------------
420+
421+
Keeps time spent on name resolving; the time is kept in seconds with millisecond resolution.
422+
423+
* Value of "" means this module does not work on this request.
424+
* Value of "-" means name resolving failed.
425+
426+
427+
$proxy_connect_connect_time
428+
---------------------------
429+
430+
Keeps time spent on establishing a connection with the upstream server; the time is kept in seconds with millisecond resolution.
431+
432+
* Value of "" means this module does not work on this request.
433+
* Value of "-" means name resolving or connecting failed.
434+
416435
Compatibility
417436
=============
418437

‎ngx_http_proxy_connect_module.c‎

Lines changed: 177 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -40,25 +40,44 @@ typedef struct {
4040
} ngx_http_proxy_connect_loc_conf_t;
4141

4242

43+
typedef struct {
44+
ngx_msec_t resolve_time;
45+
ngx_msec_t connect_time;
46+
47+
/* TODO:
48+
off_t bytes_received;
49+
off_t bytes_sent;
50+
*/
51+
} ngx_http_proxy_connect_upstream_state_t;
52+
53+
4354
struct ngx_http_proxy_connect_upstream_s {
4455
ngx_http_proxy_connect_loc_conf_t *conf;
4556

4657
ngx_http_proxy_connect_upstream_handler_pt read_event_handler;
4758
ngx_http_proxy_connect_upstream_handler_pt write_event_handler;
4859

49-
ngx_peer_connection_t peer;
60+
ngx_peer_connection_t peer;
5061

51-
ngx_http_request_t *request;
62+
ngx_http_request_t *request;
5263

53-
ngx_http_upstream_resolved_t *resolved;
64+
ngx_http_upstream_resolved_t *resolved;
5465

55-
ngx_buf_t from_client;
66+
ngx_buf_t from_client;
5667

57-
ngx_output_chain_ctx_t output;
68+
ngx_output_chain_ctx_t output;
5869

59-
ngx_buf_t buffer;
70+
ngx_buf_t buffer;
6071

61-
ngx_flag_t connected;
72+
/* 1: DNS resolving successed */
73+
ngx_flag_t _resolved;
74+
75+
/* 1: connection established */
76+
ngx_flag_t connected;
77+
78+
ngx_msec_t start_time;
79+
80+
ngx_http_proxy_connect_upstream_state_t state;
6281
};
6382

6483
struct ngx_http_proxy_connect_address_s {
@@ -108,6 +127,11 @@ static ngx_int_t ngx_http_proxy_connect_variable_get_time(ngx_http_request_t *r,
108127
ngx_http_variable_value_t *v, uintptr_t data);
109128
static void ngx_http_proxy_connect_variable_set_time(ngx_http_request_t *r,
110129
ngx_http_variable_value_t *v, uintptr_t data);
130+
static ngx_int_t ngx_http_proxy_connect_resolve_time_variable(ngx_http_request_t *r,
131+
ngx_http_variable_value_t *v, uintptr_t data);
132+
static ngx_int_t ngx_http_proxy_connect_connect_time_variable(ngx_http_request_t *r,
133+
ngx_http_variable_value_t *v, uintptr_t data);
134+
111135
static ngx_int_t ngx_http_proxy_connect_sock_ntop(ngx_http_request_t *r,
112136
ngx_http_proxy_connect_upstream_t *u);
113137
static ngx_int_t ngx_http_proxy_connect_create_peer(ngx_http_request_t *r,
@@ -233,6 +257,14 @@ static ngx_http_variable_t ngx_http_proxy_connect_vars[] = {
233257
offsetof(ngx_http_proxy_connect_ctx_t, send_timeout),
234258
NGX_HTTP_VAR_NOCACHEABLE|NGX_HTTP_VAR_CHANGEABLE, 0 },
235259

260+
{ ngx_string("proxy_connect_resolve_time"), NULL,
261+
ngx_http_proxy_connect_resolve_time_variable, 0,
262+
NGX_HTTP_VAR_NOCACHEABLE, 0 },
263+
264+
{ ngx_string("proxy_connect_connect_time"), NULL,
265+
ngx_http_proxy_connect_connect_time_variable, 0,
266+
NGX_HTTP_VAR_NOCACHEABLE, 0 },
267+
236268
{ ngx_null_string, NULL, NULL, 0, 0, 0 }
237269
};
238270

@@ -473,18 +505,22 @@ ngx_http_proxy_connect_send_connection_established(ngx_http_request_t *r)
473505

474506
ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module);
475507
c = r->connection;
508+
u = ctx->u;
476509

477510
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
478511
"proxy_connect: send 200 connection established");
479512

480-
clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
513+
u->connected = 1;
481514

482-
u = ctx->u;
515+
if (u->state.connect_time == (ngx_msec_t) -1) {
516+
u->state.connect_time = ngx_current_msec - u->start_time;
517+
}
518+
519+
clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
483520

484521
b = &ctx->buf;
485522

486523
ctx->send_established = 1;
487-
u->connected = 1;
488524

489525
for (;;) {
490526
n = c->send(c, b->pos, b->last - b->pos);
@@ -969,11 +1005,19 @@ ngx_http_proxy_connect_process_connect(ngx_http_request_t *r,
9691005

9701006
pc->get = ngx_http_proxy_connect_get_peer;
9711007

1008+
u->start_time = ngx_current_msec;
1009+
u->state.connect_time = (ngx_msec_t) -1;
1010+
9721011
rc = ngx_event_connect_peer(&u->peer);
9731012

9741013
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
9751014
"proxy_connect: ngx_event_connect_peer() returns %i", rc);
9761015

1016+
/*
1017+
* We do not retry next upstream if current connecting fails.
1018+
* So there is no ngx_http_proxy_connect_upstream_next() function
1019+
*/
1020+
9771021
if (rc == NGX_ERROR) {
9781022
ngx_http_proxy_connect_finalize_request(r, u,
9791023
NGX_HTTP_INTERNAL_SERVER_ERROR);
@@ -1106,6 +1150,12 @@ ngx_http_proxy_connect_resolve_handler(ngx_resolver_ctx_t *ctx)
11061150
ngx_resolve_name_done(ctx);
11071151
ur->ctx = NULL;
11081152

1153+
u->_resolved = 1;
1154+
1155+
if (u->state.resolve_time == (ngx_msec_t) -1) {
1156+
u->state.resolve_time = ngx_current_msec - u->start_time;
1157+
}
1158+
11091159
ngx_http_proxy_connect_process_connect(r, u);
11101160

11111161
failed:
@@ -1476,6 +1526,9 @@ ngx_http_proxy_connect_handler(ngx_http_request_t *r)
14761526
clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
14771527
temp.name = *host;
14781528

1529+
u->start_time = ngx_current_msec;
1530+
u->state.resolve_time = (ngx_msec_t) -1;
1531+
14791532
rctx = ngx_resolve_start(clcf->resolver, &temp);
14801533
if (rctx == NULL) {
14811534
ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,
@@ -1992,6 +2045,120 @@ ngx_http_proxy_connect_variable_set_time(ngx_http_request_t *r,
19922045
}
19932046

19942047

2048+
static ngx_int_t
2049+
ngx_http_proxy_connect_resolve_time_variable(ngx_http_request_t *r,
2050+
ngx_http_variable_value_t *v, uintptr_t data)
2051+
{
2052+
u_char *p;
2053+
size_t len;
2054+
ngx_msec_int_t ms;
2055+
ngx_http_proxy_connect_ctx_t *ctx;
2056+
ngx_http_proxy_connect_upstream_t *u;
2057+
2058+
if (r->method != NGX_HTTP_CONNECT) {
2059+
return NGX_OK;
2060+
}
2061+
2062+
v->valid = 1;
2063+
v->no_cacheable = 0;
2064+
v->not_found = 0;
2065+
2066+
ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module);
2067+
2068+
if (ctx == NULL) {
2069+
v->not_found = 1;
2070+
return NGX_OK;
2071+
}
2072+
2073+
u = ctx->u;
2074+
2075+
if (u == NULL || !u->resolved) {
2076+
v->not_found = 1;
2077+
return NGX_OK;
2078+
}
2079+
2080+
len = NGX_TIME_T_LEN + 4;
2081+
2082+
p = ngx_pnalloc(r->pool, len);
2083+
if (p == NULL) {
2084+
return NGX_ERROR;
2085+
}
2086+
2087+
v->data = p;
2088+
2089+
ms = u->state.resolve_time;
2090+
2091+
if (ms != -1) {
2092+
ms = ngx_max(ms, 0);
2093+
p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000);
2094+
2095+
} else {
2096+
*p++ = '-';
2097+
}
2098+
2099+
v->len = p - v->data;
2100+
2101+
return NGX_OK;
2102+
}
2103+
2104+
2105+
static ngx_int_t
2106+
ngx_http_proxy_connect_connect_time_variable(ngx_http_request_t *r,
2107+
ngx_http_variable_value_t *v, uintptr_t data)
2108+
{
2109+
u_char *p;
2110+
size_t len;
2111+
ngx_msec_int_t ms;
2112+
ngx_http_proxy_connect_ctx_t *ctx;
2113+
ngx_http_proxy_connect_upstream_t *u;
2114+
2115+
if (r->method != NGX_HTTP_CONNECT) {
2116+
return NGX_OK;
2117+
}
2118+
2119+
v->valid = 1;
2120+
v->no_cacheable = 0;
2121+
v->not_found = 0;
2122+
2123+
ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module);
2124+
2125+
if (ctx == NULL) {
2126+
v->not_found = 1;
2127+
return NGX_OK;
2128+
}
2129+
2130+
u = ctx->u;
2131+
2132+
if (u == NULL || !u->connected) {
2133+
v->not_found = 1;
2134+
return NGX_OK;
2135+
}
2136+
2137+
len = NGX_TIME_T_LEN + 4;
2138+
2139+
p = ngx_pnalloc(r->pool, len);
2140+
if (p == NULL) {
2141+
return NGX_ERROR;
2142+
}
2143+
2144+
v->data = p;
2145+
2146+
ms = u->state.connect_time;
2147+
2148+
if (ms != -1) {
2149+
ms = ngx_max(ms, 0);
2150+
p = ngx_sprintf(p, "%T.%03M", (time_t) ms / 1000, ms % 1000);
2151+
2152+
} else {
2153+
*p++ = '-';
2154+
}
2155+
2156+
v->len = p - v->data;
2157+
2158+
return NGX_OK;
2159+
}
2160+
2161+
19952162
static ngx_int_t
19962163
ngx_http_proxy_connect_add_variables(ngx_conf_t *cf)
19972164
{

0 commit comments

Comments
 (0)