Skip to content

Commit

Permalink
refactor logic of handling proxy timer
Browse files Browse the repository at this point in the history 
1. Refactor timer logic in ngx_http_proxy_connect_tunnel(), refer to
   ngx_stream_proxy_process() in ngx_stream_proxy_module. It only adds
   one timer after it processes r/w operations on client or proxied
   server connections.
2. With the new timer logic, it will fix connection break that it continues
   to upload data to backend
3. The directive `proxy_connect_read_timeout` has been changed to:
   Sets the timeout between two successive read or write operations on
   client or proxied server connections. If no data is transmitted
   within this time, the connection is closed.
4. The directive `proxy_connect_send_timeout` has been deprecated.
5. Added new test cases and documentation for new timer logic
  • Loading branch information
@chobits
chobits committed Nov 24, 2022
1 parent 834a1c7 commit bed2a08
Show file tree
Hide file tree
Showing 3 changed files with 79 additions and 72 deletions.
11 changes: 4 additions & 7 deletions README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -337,9 +337,7 @@ Syntax: **proxy_connect_read_timeout `time`**
Default: `60s`
Context: `server`

Defines a timeout for reading a response from the proxied server.
The timeout is set only between two successive read operations, not for the transmission of the whole response.
If the proxied server does not transmit anything within this time, the connection is closed.
Sets the timeout between two successive read or write operations on client or proxied server connections. If no data is transmitted within this time, the connection is closed.

proxy_connect_send_timeout
--------------------------
Expand All @@ -348,9 +346,8 @@ Syntax: **proxy_connect_send_timeout `time`**
Default: `60s`
Context: `server`

Sets a timeout for transmitting a request to the proxied server.
The timeout is set only between two successive write operations, not for the transmission of the whole request.
If the proxied server does not receive anything within this time, the connection is closed.
Deprecated, it has no function.
Use the directive `proxy_connect_read_timeout` instead for both read and write operations.

proxy_connect_address
---------------------
Expand Down Expand Up @@ -473,7 +470,7 @@ Get or set a timeout of [`proxy_connect_read_timeout` directive](#proxy_connect_
$proxy_connect_send_timeout
---------------------------

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

$proxy_connect_resolve_time
---------------------------
Expand Down
112 changes: 48 additions & 64 deletions ngx_http_proxy_connect_module.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -617,9 +617,10 @@ ngx_http_proxy_connect_send_connection_established(ngx_http_request_t *r)
}

/* n == NGX_AGAIN */

r->write_event_handler = ngx_http_proxy_connect_send_handler;

ngx_add_timer(c->write, ctx->send_timeout);
ngx_add_timer(c->write, ctx->read_timeout);

if (ngx_handle_write_event(c->write, clcf->send_lowat) != NGX_OK) {
ngx_http_proxy_connect_finalize_request(r, u,
Expand All @@ -635,11 +636,12 @@ static void
ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,
ngx_uint_t from_upstream, ngx_uint_t do_write)
{
char *recv_action, *send_action;
size_t size;
ssize_t n;
ngx_buf_t *b;
ngx_connection_t *c, *downstream, *upstream, *dst, *src;
ngx_http_core_loc_conf_t *clcf;
ngx_uint_t flags;
ngx_connection_t *c, *pc, *dst, *src;
ngx_http_proxy_connect_ctx_t *ctx;
ngx_http_proxy_connect_upstream_t *u;

Expand All @@ -652,17 +654,19 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,
"proxy_connect: tunnel fu:%ui write:%ui",
from_upstream, do_write);

downstream = c;
upstream = u->peer.connection;
c = c;
pc = u->peer.connection;

if (from_upstream) {
src = upstream;
dst = downstream;
src = pc;
dst = c;
b = &u->buffer;
recv_action = "proxying and reading from upstream";
send_action = "proxying and sending to client";

} else {
src = downstream;
dst = upstream;
src = c;
dst = pc;
b = &u->from_client;

if (r->header_in->last > r->header_in->pos) {
Expand All @@ -683,6 +687,8 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,
b->end = b->start + u->conf->buffer_size;
b->temporary = 1;
}
recv_action = "proxying and reading from client";
send_action = "proxying and sending to upstream";
}

for ( ;; ) {
Expand All @@ -692,6 +698,7 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,
size = b->last - b->pos;

if (size && dst->write->ready) {
c->log->action = send_action;

n = dst->send(dst, b->pos, size);

Expand Down Expand Up @@ -719,6 +726,8 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,

if (size && src->read->ready) {

c->log->action = recv_action;

n = src->recv(src, b->last, size);

if (n == NGX_AGAIN || n == 0) {
Expand Down Expand Up @@ -747,72 +756,39 @@ ngx_http_proxy_connect_tunnel(ngx_http_request_t *r,
break;
}

if ((upstream->read->eof && u->buffer.pos == u->buffer.last)
|| (downstream->read->eof && u->from_client.pos == u->from_client.last)
|| (downstream->read->eof && upstream->read->eof))
c->log->action = "proxying connection";

/* test finalize */

if ((pc->read->eof && u->buffer.pos == u->buffer.last)
|| (c->read->eof && u->from_client.pos == u->from_client.last)
|| (c->read->eof && pc->read->eof))
{
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, c->log, 0,
"proxy_connect: tunnel done");
ngx_http_proxy_connect_finalize_request(r, u, 0);
return;
}

clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
flags = src->read->eof ? NGX_CLOSE_EVENT : 0;

if (ngx_handle_write_event(upstream->write, u->conf->send_lowat)
!= NGX_OK)
{
if (ngx_handle_read_event(src->read, flags) != NGX_OK) {
ngx_http_proxy_connect_finalize_request(r, u, NGX_ERROR);
return;
}

if (upstream->write->active && !upstream->write->ready) {
ngx_add_timer(upstream->write, ctx->send_timeout);

} else if (upstream->write->timer_set) {
ngx_del_timer(upstream->write);
}

if (ngx_handle_read_event(upstream->read, 0) != NGX_OK) {
ngx_http_proxy_connect_finalize_request(r, u, NGX_ERROR);
return;
}

if (upstream->read->active && !upstream->read->ready) {
if (from_upstream) {
ngx_add_timer(upstream->read, ctx->read_timeout);
if (dst) {
if (ngx_handle_write_event(dst->write, 0) != NGX_OK) {
ngx_http_proxy_connect_finalize_request(r, u, NGX_ERROR);
return;
}

} else if (upstream->read->timer_set) {
ngx_del_timer(upstream->read);
}
if (!c->read->delayed && !pc->read->delayed) {
ngx_add_timer(c->write, ctx->read_timeout);

if (ngx_handle_write_event(downstream->write, clcf->send_lowat)
!= NGX_OK)
{
ngx_http_proxy_connect_finalize_request(r, u, NGX_ERROR);
return;
}

if (ngx_handle_read_event(downstream->read, 0) != NGX_OK) {
ngx_http_proxy_connect_finalize_request(r, u, NGX_ERROR);
return;
}

if (downstream->write->active && !downstream->write->ready) {
ngx_add_timer(downstream->write, clcf->send_timeout);

} else if (downstream->write->timer_set) {
ngx_del_timer(downstream->write);
}

if (downstream->read->active && !downstream->read->ready) {
if (!from_upstream) {
ngx_add_timer(downstream->read, clcf->client_body_timeout);
} else if (c->write->timer_set) {
ngx_del_timer(c->write);
}

} else if (downstream->read->timer_set) {
ngx_del_timer(downstream->read);
}
}

Expand All @@ -822,6 +798,10 @@ ngx_http_proxy_connect_read_downstream(ngx_http_request_t *r)
{
ngx_http_proxy_connect_ctx_t *ctx;


ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"proxy connect read downstream");

ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module);

if (r->connection->read->timedout) {
Expand All @@ -842,12 +822,15 @@ ngx_http_proxy_connect_write_downstream(ngx_http_request_t *r)
{
ngx_http_proxy_connect_ctx_t *ctx;

ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"proxy connect write downstream");

ctx = ngx_http_get_module_ctx(r, ngx_http_proxy_connect_module);

if (r->connection->write->timedout) {
r->connection->timedout = 1;
ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,
"proxy_connect: client write timed out");
ngx_connection_error(r->connection, NGX_ETIMEDOUT,
"proxy_connect: connection timed out");
ngx_http_proxy_connect_finalize_request(r, ctx->u,
NGX_HTTP_REQUEST_TIME_OUT);
return;
Expand Down Expand Up @@ -923,8 +906,9 @@ ngx_http_proxy_connect_write_upstream(ngx_http_request_t *r,

c = u->peer.connection;

ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"proxy_connect: upstream write handler");
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"proxy_connect: upstream write handler %s",
u->connected ? "" : "(connect)");

if (c->write->timedout) {
ngx_log_error(NGX_LOG_ERR, c->log, 0,
Expand Down Expand Up @@ -1390,7 +1374,7 @@ ngx_http_proxy_connect_check_broken_connection(ngx_http_request_t *r,
err = ngx_socket_errno;

ngx_log_debug1(NGX_LOG_DEBUG_HTTP, ev->log, err,
"proxy_connect: upstream recv(): %d", n);
"proxy_connect: client recv(): %d", n);

if (ev->write && (n >= 0 || err == NGX_EAGAIN)) {
return;
Expand Down
28 changes: 27 additions & 1 deletion t/http_proxy_connect_resolve_variables.t
View file
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ http {
'fbt:$proxy_connect_first_byte_time,';
access_log %%TESTDIR%%/connect.log connect;
error_log %%TESTDIR%%/connect_error.log error;
error_log %%TESTDIR%%/connect_error.log info;
resolver 127.0.0.1:18085 ipv6=off; # NOTE: cannot connect ipv6 address ::1 in mac os x.
Expand Down Expand Up @@ -136,6 +136,16 @@ http {
set $proxy_connect_read_timeout "700ms";
}
if ($request ~ "127.0.0.01:8082") {
# must be less than 1s (server 8082 lua sleep(1s))
set $proxy_connect_read_timeout "800ms";
}
if ($request ~ "127.0.0.01:8083") {
# must be less than 0.5s (server 8082 lua sleep(1s))
set $proxy_connect_read_timeout "300ms";
}
location / {
proxy_pass http://127.0.0.01:8081;
}
Expand Down Expand Up @@ -242,6 +252,22 @@ like($t->read_file('connect.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');

# test timeout
$t->write_file('connect_error.log', "");
$r = http_connect_request('127.0.0.01', '8082', '/');
is($r, "", "test first byte time: 1s, timeout");
#'2022/11/24 20:51:13 [info] 15239#0: *15 proxy_connect: connection timed out (110: Connection timed out) while proxying connection, client: 127.0.0.1, server: localhost, request: "CONNECT 127.0.0.01:8082 HTTP/1.1", host: "127.0.0.01"
like($t->read_file('connect_error.log'),
qr/\[info\].* proxy_connect: connection timed out.+ request: "CONNECT 127\.0\.0\.01:8082 HTTP\/..."/,
'test first byte time: 1s, check timeout in error log');

$t->write_file('connect_error.log', "");
$r = http_connect_request('127.0.0.01', '8083', '/');
is($r, "", "test first byte time: 0.5s, timeout");
like($t->read_file('connect_error.log'),
qr/\[info\].* proxy_connect: connection timed out.+ request: "CONNECT 127\.0\.0\.01:8083 HTTP\/..."/,
'test first byte time: 1s, check timeout in error log');

$t->stop();


Expand Down

0 comments on commit bed2a08

Please sign in to comment.