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.

diff --git a/src/http/ngx_http_request.c b/src/http/ngx_http_request.c
index 5a39c118afd1347488955f80216d11d2c0ac1408..fd790e10bd594bc8795677ad9056d07e4255358f 100644 (file)
--- 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_request_t *r)
                                 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);
         }

diff --git a/src/http/v2/ngx_http_v2.c b/src/http/v2/ngx_http_v2.c
index e4f824cfe2231d01937a7d8804758f241c8ea5ca..4c4a4e7a9155533d7fe5883aed53048b45c2be5f 100644 (file)
--- 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(ngx_http_v2_connection_t *h2c,
     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_http_request_t *r,
 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 *wev)
                        "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_connection_t *h2c, u_char *pos,
     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_connection_t *h2c, u_char *pos,
         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_connection_t *h2c, u_char *pos,
         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_connection_t *h2c, u_char *pos,
             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_connection_t *h2c, u_char *pos,
     }
 
     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_connection_t *h2c, u_char *pos,
             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_connection_t *h2c, u_char *pos,
         }
 
         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_connection_t *h2c, u_char *pos,
 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_v2_connection_t *h2c, u_char *pos,
     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_v2_connection_t *h2c, u_char *pos,
 
     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_connection_t *h2c, u_char *pos,
     }
 
     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_connection_t *h2c, u_char *pos,
 
     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_connection_t *h2c, u_char *pos,
     }
 
     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_connection_t *h2c, u_char *pos,
     }
 
     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_v2_connection_t *h2c, u_char *pos,
     }
 
     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_v2_connection_t *h2c, u_char *pos,
 
             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_v2_connection_t *h2c, u_char *pos,
 
         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) {
@@ -2370,6 +2399,28 @@ ngx_http_v2_state_save(ngx_http_v2_connection_t *h2c, u_char *pos, u_char *end,
 }
 
 
+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_connection_t *h2c)
     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_request_t *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_stream_t *stream, ngx_int_t rc)
 
     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_stream_t *stream, ngx_int_t rc)
 
     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_stream_t *stream, ngx_int_t rc)
 
     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_event_t *ev)
     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_event_t *ev)
 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(ngx_event_t *rev)
     }
 
     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_v2_connection_t *h2c,
 
             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_connection_t *h2c, ssize_t delta)
 
                 wev = stream->request->connection->write;
 
-                if (!wev->timer_set) {
-                    wev->delayed = 0;
+                wev->active = 0;
+                wev->ready = 1;
+
+                if (!wev->delayed) {
                     wev->handler(wev);
                 }
             }

diff --git a/src/http/v2/ngx_http_v2_filter_module.c b/src/http/v2/ngx_http_v2_filter_module.c
index 3e396ab54368dbe1db954d361ccb0119a02808a5..caa835dec31b25f682665afada1cb50e0a6baaab 100644 (file)
--- 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 *fc, ngx_chain_t *in, off_t limit)
     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 *fc, ngx_chain_t *in, off_t limit)
     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 *fc, ngx_chain_t *in, off_t limit)
     }
 
     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 *fc, ngx_http_v2_stream_t *stream)
 
     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_connection_t *h2c,
 
     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);
     }