changeset 6412:4ba91a4c66a3

HTTP/2: implemented per request timeouts (closes #626). Previously, there were only three timeouts used globally for the whole HTTP/2 connection: 1. Idle timeout for inactivity when there are no streams in processing (the "http2_idle_timeout" directive); 2. Receive timeout for incomplete frames when there are no streams in processing (the "http2_recv_timeout" directive); 3. Send timeout when there are frames waiting in the output queue (the "send_timeout" directive on a server level). Reaching one of these timeouts leads to HTTP/2 connection close. This left a number of scenarios when a connection can get stuck without any processing and timeouts: 1. A client has sent the headers block partially so nginx starts processing a new stream but cannot continue without the rest of HEADERS and/or CONTINUATION frames; 2. When nginx waits for the request body; 3. All streams are stuck on exhausted connection or stream windows. The first idea that was rejected was to detect when the whole connection gets stuck because of these situations and set the global receive timeout. The disadvantage of such approach would be inconsistent behaviour in some typical use cases. For example, if a user never replies to the browser's question about where to save the downloaded file, the stream will be eventually closed by a timeout. On the other hand, this will not happen if there's some activity in other concurrent streams. Now almost all the request timeouts work like in HTTP/1.x connections, so the "client_header_timeout", "client_body_timeout", and "send_timeout" are respected. These timeouts close the request. The global timeouts work as before. Previously, the c->write->delayed flag was abused to avoid setting timeouts on stream events. Now, the "active" and "ready" flags are manipulated instead to control the processing of individual streams.
author Valentin Bartenev <vbart@nginx.com>
date Wed, 24 Feb 2016 15:58:07 +0300
parents 8ec349bb60b2
children ead3907d74f9
files src/http/ngx_http_request.c src/http/v2/ngx_http_v2.c src/http/v2/ngx_http_v2_filter_module.c
diffstat 3 files changed, 147 insertions(+), 63 deletions(-) [+]
line wrap: on
line diff
--- a/src/http/ngx_http_request.c
+++ b/src/http/ngx_http_request.c
@@ -2573,12 +2573,6 @@ ngx_http_set_write_handler(ngx_http_requ
                                 ngx_http_test_reading;
     r->write_event_handler = ngx_http_writer;
 
-#if (NGX_HTTP_V2)
-    if (r->stream) {
-        return NGX_OK;
-    }
-#endif
-
     wev = r->connection->write;
 
     if (wev->ready && wev->delayed) {
@@ -2664,12 +2658,6 @@ ngx_http_writer(ngx_http_request_t *r)
 
     if (r->buffered || r->postponed || (r == r->main && c->buffered)) {
 
-#if (NGX_HTTP_V2)
-        if (r->stream) {
-            return;
-        }
-#endif
-
         if (!wev->delayed) {
             ngx_add_timer(wev, clcf->send_timeout);
         }
--- a/src/http/v2/ngx_http_v2.c
+++ b/src/http/v2/ngx_http_v2.c
@@ -114,6 +114,8 @@ static u_char *ngx_http_v2_state_skip(ng
     u_char *pos, u_char *end);
 static u_char *ngx_http_v2_state_save(ngx_http_v2_connection_t *h2c,
     u_char *pos, u_char *end, ngx_http_v2_handler_pt handler);
+static u_char *ngx_http_v2_state_headers_save(ngx_http_v2_connection_t *h2c,
+    u_char *pos, u_char *end, ngx_http_v2_handler_pt handler);
 static u_char *ngx_http_v2_connection_error(ngx_http_v2_connection_t *h2c,
     ngx_uint_t err);
 
@@ -162,6 +164,7 @@ static ngx_int_t ngx_http_v2_cookie(ngx_
 static ngx_int_t ngx_http_v2_construct_cookie_header(ngx_http_request_t *r);
 static void ngx_http_v2_run_request(ngx_http_request_t *r);
 static ngx_int_t ngx_http_v2_init_request_body(ngx_http_request_t *r);
+static void ngx_http_v2_read_client_request_body_handler(ngx_http_request_t *r);
 
 static ngx_int_t ngx_http_v2_terminate_stream(ngx_http_v2_connection_t *h2c,
     ngx_http_v2_stream_t *stream, ngx_uint_t status);
@@ -430,6 +433,10 @@ ngx_http_v2_write_handler(ngx_event_t *w
                        "run http2 stream %ui", stream->node->id);
 
         wev = stream->request->connection->write;
+
+        wev->active = 0;
+        wev->ready = 1;
+
         wev->handler(wev);
     }
 
@@ -883,6 +890,7 @@ ngx_http_v2_state_read_data(ngx_http_v2_
     ngx_buf_t                 *buf;
     ngx_int_t                  rc;
     ngx_temp_file_t           *tf;
+    ngx_connection_t          *fc;
     ngx_http_request_t        *r;
     ngx_http_v2_stream_t      *stream;
     ngx_http_request_body_t   *rb;
@@ -919,6 +927,7 @@ ngx_http_v2_state_read_data(ngx_http_v2_
         return ngx_http_v2_state_skip_padded(h2c, pos, end);
     }
 
+    fc = r->connection;
     rb = r->request_body;
     tf = rb->temp_file;
     buf = rb->buf;
@@ -929,7 +938,7 @@ ngx_http_v2_state_read_data(ngx_http_v2_
         if (r->headers_in.content_length_n != -1
             && r->headers_in.content_length_n < rb->rest)
         {
-            ngx_log_error(NGX_LOG_INFO, r->connection->log, 0,
+            ngx_log_error(NGX_LOG_INFO, fc->log, 0,
                           "client intended to send body data "
                           "larger than declared");
 
@@ -942,7 +951,7 @@ ngx_http_v2_state_read_data(ngx_http_v2_
             if (clcf->client_max_body_size
                 && clcf->client_max_body_size < rb->rest)
             {
-                ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,
+                ngx_log_error(NGX_LOG_ERR, fc->log, 0,
                               "client intended to send "
                               "too large chunked body: %O bytes", rb->rest);
 
@@ -982,6 +991,11 @@ ngx_http_v2_state_read_data(ngx_http_v2_
     }
 
     if (h2c->state.length) {
+        if (rb->post_handler) {
+            clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
+            ngx_add_timer(fc->read, clcf->client_body_timeout);
+        }
+
         return ngx_http_v2_state_save(h2c, pos, end,
                                       ngx_http_v2_state_read_data);
     }
@@ -993,7 +1007,7 @@ ngx_http_v2_state_read_data(ngx_http_v2_
             r->headers_in.content_length_n = rb->rest;
 
         } else if (r->headers_in.content_length_n != rb->rest) {
-            ngx_log_error(NGX_LOG_INFO, r->connection->log, 0,
+            ngx_log_error(NGX_LOG_INFO, fc->log, 0,
                           "client prematurely closed stream: "
                           "only %O out of %O bytes of request body received",
                           rb->rest, r->headers_in.content_length_n);
@@ -1013,9 +1027,17 @@ ngx_http_v2_state_read_data(ngx_http_v2_
         }
 
         if (rb->post_handler) {
+            if (fc->read->timer_set) {
+                ngx_del_timer(fc->read);
+            }
+
             r->read_event_handler = ngx_http_block_reading;
             rb->post_handler(r);
         }
+
+    } else if (rb->post_handler) {
+        clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
+        ngx_add_timer(fc->read, clcf->client_body_timeout);
     }
 
     if (h2c->state.padding) {
@@ -1027,6 +1049,9 @@ ngx_http_v2_state_read_data(ngx_http_v2_
 error:
 
     if (rb->post_handler) {
+        if (fc->read->timer_set) {
+            ngx_del_timer(fc->read);
+        }
 
         if (stream->skip_data == NGX_HTTP_V2_DATA_ERROR) {
             rc = (r->headers_in.content_length_n == -1)
@@ -1218,8 +1243,8 @@ ngx_http_v2_state_header_block(ngx_http_
     ngx_uint_t  indexed, size_update, prefix;
 
     if (end - pos < 1) {
-        return ngx_http_v2_state_save(h2c, pos, end,
-                                      ngx_http_v2_state_header_block);
+        return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                              ngx_http_v2_state_header_block);
     }
 
     if (!(h2c->state.flags & NGX_HTTP_V2_END_HEADERS_FLAG)
@@ -1262,8 +1287,8 @@ ngx_http_v2_state_header_block(ngx_http_
 
     if (value < 0) {
         if (value == NGX_AGAIN) {
-            return ngx_http_v2_state_save(h2c, pos, end,
-                                          ngx_http_v2_state_header_block);
+            return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                               ngx_http_v2_state_header_block);
         }
 
         if (value == NGX_DECLINED) {
@@ -1333,8 +1358,8 @@ ngx_http_v2_state_field_len(ngx_http_v2_
     }
 
     if (end - pos < 1) {
-        return ngx_http_v2_state_save(h2c, pos, end,
-                                      ngx_http_v2_state_field_len);
+        return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                              ngx_http_v2_state_field_len);
     }
 
     huff = *pos >> 7;
@@ -1342,8 +1367,8 @@ ngx_http_v2_state_field_len(ngx_http_v2_
 
     if (len < 0) {
         if (len == NGX_AGAIN) {
-            return ngx_http_v2_state_save(h2c, pos, end,
-                                          ngx_http_v2_state_field_len);
+            return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                                  ngx_http_v2_state_field_len);
         }
 
         if (len == NGX_DECLINED) {
@@ -1435,8 +1460,8 @@ ngx_http_v2_state_field_huff(ngx_http_v2
     }
 
     if (h2c->state.length) {
-        return ngx_http_v2_state_save(h2c, pos, end,
-                                      ngx_http_v2_state_field_huff);
+        return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                              ngx_http_v2_state_field_huff);
     }
 
     if (h2c->state.flags & NGX_HTTP_V2_END_HEADERS_FLAG) {
@@ -1480,8 +1505,8 @@ ngx_http_v2_state_field_raw(ngx_http_v2_
     }
 
     if (h2c->state.length) {
-        return ngx_http_v2_state_save(h2c, pos, end,
-                                      ngx_http_v2_state_field_raw);
+        return ngx_http_v2_state_headers_save(h2c, pos, end,
+                                              ngx_http_v2_state_field_raw);
     }
 
     if (h2c->state.flags & NGX_HTTP_V2_END_HEADERS_FLAG) {
@@ -1754,7 +1779,7 @@ ngx_http_v2_handle_continuation(ngx_http
     }
 
     if ((size_t) (end - pos) < len + NGX_HTTP_V2_FRAME_HEADER_SIZE) {
-        return ngx_http_v2_state_save(h2c, pos, end, handler);
+        return ngx_http_v2_state_headers_save(h2c, pos, end, handler);
     }
 
     p = pos + len;
@@ -2229,8 +2254,10 @@ ngx_http_v2_state_window_update(ngx_http
 
             wev = stream->request->connection->write;
 
-            if (!wev->timer_set) {
-                wev->delayed = 0;
+            wev->active = 0;
+            wev->ready = 1;
+
+            if (!wev->delayed) {
                 wev->handler(wev);
             }
         }
@@ -2262,8 +2289,10 @@ ngx_http_v2_state_window_update(ngx_http
 
         wev = stream->request->connection->write;
 
-        if (!wev->timer_set) {
-            wev->delayed = 0;
+        wev->active = 0;
+        wev->ready = 1;
+
+        if (!wev->delayed) {
             wev->handler(wev);
 
             if (h2c->send_window == 0) {
@@ -2371,6 +2400,28 @@ ngx_http_v2_state_save(ngx_http_v2_conne
 
 
 static u_char *
+ngx_http_v2_state_headers_save(ngx_http_v2_connection_t *h2c, u_char *pos,
+    u_char *end, ngx_http_v2_handler_pt handler)
+{
+    ngx_event_t               *rev;
+    ngx_http_request_t        *r;
+    ngx_http_core_srv_conf_t  *cscf;
+
+    if (h2c->state.stream) {
+        r = h2c->state.stream->request;
+        rev = r->connection->read;
+
+        if (!rev->timer_set) {
+            cscf = ngx_http_get_module_srv_conf(r, ngx_http_core_module);
+            ngx_add_timer(rev, cscf->client_header_timeout);
+        }
+    }
+
+    return ngx_http_v2_state_save(h2c, pos, end, handler);
+}
+
+
+static u_char *
 ngx_http_v2_connection_error(ngx_http_v2_connection_t *h2c,
     ngx_uint_t err)
 {
@@ -2748,6 +2799,7 @@ ngx_http_v2_create_stream(ngx_http_v2_co
     ngx_memcpy(log, h2c->connection->log, sizeof(ngx_log_t));
 
     log->data = ctx;
+    log->action = "reading client request headers";
 
     ngx_memzero(rev, sizeof(ngx_event_t));
 
@@ -3554,7 +3606,8 @@ ngx_int_t
 ngx_http_v2_read_request_body(ngx_http_request_t *r,
     ngx_http_client_body_handler_pt post_handler)
 {
-    ngx_http_v2_stream_t  *stream;
+    ngx_http_v2_stream_t      *stream;
+    ngx_http_core_loc_conf_t  *clcf;
 
     ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
                    "http2 read request body");
@@ -3590,13 +3643,48 @@ ngx_http_v2_read_request_body(ngx_http_r
 
     r->request_body->post_handler = post_handler;
 
-    r->read_event_handler = ngx_http_test_reading;
+    r->read_event_handler = ngx_http_v2_read_client_request_body_handler;
     r->write_event_handler = ngx_http_request_empty_handler;
 
+    clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
+    ngx_add_timer(r->connection->read, clcf->client_body_timeout);
+
     return NGX_AGAIN;
 }
 
 
+static void
+ngx_http_v2_read_client_request_body_handler(ngx_http_request_t *r)
+{
+    ngx_connection_t  *fc;
+
+    fc = r->connection;
+
+    ngx_log_debug0(NGX_LOG_DEBUG_HTTP, fc->log, 0,
+                   "http2 read client request body handler");
+
+    if (fc->read->timedout) {
+        ngx_log_error(NGX_LOG_INFO, fc->log, NGX_ETIMEDOUT, "client timed out");
+
+        fc->timedout = 1;
+        r->stream->skip_data = NGX_HTTP_V2_DATA_DISCARD;
+
+        ngx_http_finalize_request(r, NGX_HTTP_REQUEST_TIME_OUT);
+        return;
+    }
+
+    if (fc->error) {
+        ngx_log_error(NGX_LOG_INFO, fc->log, 0,
+                      "client prematurely closed stream");
+
+        r->stream->skip_data = NGX_HTTP_V2_DATA_DISCARD;
+
+        ngx_http_finalize_request(r, NGX_HTTP_CLIENT_CLOSED_REQUEST);
+        return;
+    }
+}
+
+
 static ngx_int_t
 ngx_http_v2_terminate_stream(ngx_http_v2_connection_t *h2c,
     ngx_http_v2_stream_t *stream, ngx_uint_t status)
@@ -3647,7 +3735,8 @@ ngx_http_v2_close_stream(ngx_http_v2_str
 
     if (!stream->out_closed) {
         if (ngx_http_v2_send_rst_stream(h2c, node->id,
-                                        NGX_HTTP_V2_INTERNAL_ERROR)
+                                     fc->timedout ? NGX_HTTP_V2_PROTOCOL_ERROR
+                                                  : NGX_HTTP_V2_INTERNAL_ERROR)
             != NGX_OK)
         {
             h2c->connection->error = 1;
@@ -3684,11 +3773,6 @@ ngx_http_v2_close_stream(ngx_http_v2_str
 
     ev = fc->read;
 
-    if (ev->active || ev->disabled) {
-        ngx_log_error(NGX_LOG_ALERT, h2c->connection->log, 0,
-                      "fake read event was activated");
-    }
-
     if (ev->timer_set) {
         ngx_del_timer(ev);
     }
@@ -3699,11 +3783,6 @@ ngx_http_v2_close_stream(ngx_http_v2_str
 
     ev = fc->write;
 
-    if (ev->active || ev->disabled) {
-        ngx_log_error(NGX_LOG_ALERT, h2c->connection->log, 0,
-                      "fake write event was activated");
-    }
-
     if (ev->timer_set) {
         ngx_del_timer(ev);
     }
@@ -3737,9 +3816,18 @@ ngx_http_v2_close_stream_handler(ngx_eve
     fc = ev->data;
     r = fc->data;
 
-    ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
+    ngx_log_debug0(NGX_LOG_DEBUG_HTTP, fc->log, 0,
                    "http2 close stream handler");
 
+    if (ev->timedout) {
+        ngx_log_error(NGX_LOG_INFO, fc->log, NGX_ETIMEDOUT, "client timed out");
+
+        fc->timedout = 1;
+
+        ngx_http_v2_close_stream(r->stream, NGX_HTTP_REQUEST_TIME_OUT);
+        return;
+    }
+
     ngx_http_v2_close_stream(r->stream, 0);
 }
 
@@ -3747,7 +3835,11 @@ ngx_http_v2_close_stream_handler(ngx_eve
 static void
 ngx_http_v2_handle_connection_handler(ngx_event_t *rev)
 {
-    ngx_connection_t  *c;
+    ngx_connection_t          *c;
+    ngx_http_v2_connection_t  *h2c;
+
+    ngx_log_debug0(NGX_LOG_DEBUG_HTTP, rev->log, 0,
+                   "http2 handle connection handler");
 
     rev->handler = ngx_http_v2_read_handler;
 
@@ -3757,6 +3849,12 @@ ngx_http_v2_handle_connection_handler(ng
     }
 
     c = rev->data;
+    h2c = c->data;
+
+    if (h2c->last_out && ngx_http_v2_send_output_queue(h2c) == NGX_ERROR) {
+        ngx_http_v2_finalize_connection(h2c, 0);
+        return;
+    }
 
     ngx_http_v2_handle_connection(c->data);
 }
@@ -3878,9 +3976,7 @@ ngx_http_v2_finalize_connection(ngx_http
 
             if (stream->queued) {
                 stream->queued = 0;
-
                 ev = fc->write;
-                ev->delayed = 0;
 
             } else {
                 ev = fc->read;
@@ -3949,8 +4045,10 @@ ngx_http_v2_adjust_windows(ngx_http_v2_c
 
                 wev = stream->request->connection->write;
 
-                if (!wev->timer_set) {
-                    wev->delayed = 0;
+                wev->active = 0;
+                wev->ready = 1;
+
+                if (!wev->delayed) {
                     wev->handler(wev);
                 }
             }
--- a/src/http/v2/ngx_http_v2_filter_module.c
+++ b/src/http/v2/ngx_http_v2_filter_module.c
@@ -799,7 +799,9 @@ ngx_http_v2_send_chain(ngx_connection_t 
     if (in == NULL) {
 
         if (stream->queued) {
-            fc->write->delayed = 1;
+            fc->write->active = 1;
+            fc->write->ready = 0;
+
         } else {
             fc->buffered &= ~NGX_HTTP_V2_BUFFERED;
         }
@@ -810,7 +812,8 @@ ngx_http_v2_send_chain(ngx_connection_t 
     h2c = stream->connection;
 
     if (size && ngx_http_v2_flow_control(h2c, stream) == NGX_DECLINED) {
-        fc->write->delayed = 1;
+        fc->write->active = 1;
+        fc->write->ready = 0;
         return in;
     }
 
@@ -947,7 +950,8 @@ ngx_http_v2_send_chain(ngx_connection_t 
     }
 
     if (in && ngx_http_v2_flow_control(h2c, stream) == NGX_DECLINED) {
-        fc->write->delayed = 1;
+        fc->write->active = 1;
+        fc->write->ready = 0;
     }
 
     return in;
@@ -1078,7 +1082,8 @@ ngx_http_v2_filter_send(ngx_connection_t
 
     if (stream->queued) {
         fc->buffered |= NGX_HTTP_V2_BUFFERED;
-        fc->write->delayed = 1;
+        fc->write->active = 1;
+        fc->write->ready = 0;
         return NGX_AGAIN;
     }
 
@@ -1316,14 +1321,7 @@ ngx_http_v2_handle_stream(ngx_http_v2_co
 
     wev = stream->request->connection->write;
 
-    /*
-     * This timer can only be set if the stream was delayed because of rate
-     * limit.  In that case the event should be triggered by the timer.
-     */
-
-    if (!wev->timer_set) {
-        wev->delayed = 0;
-
+    if (!wev->delayed) {
         stream->handled = 1;
         ngx_queue_insert_tail(&h2c->posted, &stream->queue);
     }