when normal read timeout expires, http2 switches to its keepalive timeout, on async...

git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1721187 13f79535-47bb-0310-9956-ffa450edef68

diff --git a/CHANGES b/CHANGES
index 1f83c06f71e4f29cd6592e20383648dabc8e88fc..cbe47436e6fc9cd76e9feddf222d04206241b0b7 100644 (file)
--- a/CHANGES
+++ b/CHANGES
@@ -1,6 +1,10 @@
                                                          -*- coding: utf-8 -*-
 Changes with Apache 2.5.0
 
+  *) mod_http2: On async MPMs (event), idle HTTP/2 connections will enter KEEPALIVE
+     state and become eligible for MPM cleanup under load.
+     [Stefan Eissing]
+
   *) mod_http2: new r->subprocess_env variables HTTP2 and H2PUSH, set to "on"
      when available for request.
      [Stefan Eissing]

diff --git a/modules/http2/h2_config.c b/modules/http2/h2_config.c
index 75f6d71cd5873394177921e0b7137b19f55fb27b..329609923fd1296c8217d5b6c61d5bae93c77b91 100644 (file)
--- a/modules/http2/h2_config.c
+++ b/modules/http2/h2_config.c
@@ -60,8 +60,8 @@ static h2_config defconf = {
     1,                      /* HTTP/2 server push enabled */
     NULL,                   /* map of content-type to priorities */
     5,                      /* normal connection timeout */
-    5*60,                   /* idle connection timeout */
-    2*60,                   /* stream timeout */
+    30,                     /* idle connection timeout */
+    0,                      /* stream timeout */
 };
 
 static int files_per_session;

diff --git a/modules/http2/h2_conn.c b/modules/http2/h2_conn.c
index 5c766e84ec5e8be90c90673ea1afe18ef4c2c985..c7c249cf9071942c814b3ae720f83731f511c6cc 100644 (file)
--- a/modules/http2/h2_conn.c
+++ b/modules/http2/h2_conn.c
@@ -125,7 +125,6 @@ apr_status_t h2_conn_setup(h2_ctx *ctx, conn_rec *c, request_rec *r)
 {
     h2_session *session;
     
-    ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, c, "setup");
     if (!workers) {
         ap_log_cerror(APLOG_MARK, APLOG_ERR, 0, c, APLOGNO(02911) 
                       "workers not initialized");
@@ -156,9 +155,9 @@ apr_status_t h2_conn_process(h2_ctx *ctx, int async)
         session->c->cs->sense = CONN_SENSE_DEFAULT;
     }
 
-    ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, "process");
     status = h2_session_process(session, async);
 
+    session->c->keepalive = AP_CONN_KEEPALIVE;
     if (session->c->cs) {
         session->c->cs->state = CONN_STATE_WRITE_COMPLETION;
     }
@@ -171,10 +170,7 @@ apr_status_t h2_conn_process(h2_ctx *ctx, int async)
         session->c->keepalive = AP_CONN_CLOSE;
         
         h2_session_close(session);
-        /* hereafter session will be gone */
-    }
-    else {
-        session->c->keepalive = AP_CONN_KEEPALIVE;
+        /* hereafter session may be gone */
     }
     
     return DONE;

diff --git a/modules/http2/h2_session.c b/modules/http2/h2_session.c
index 3b624a8f331ff97fa9ab9dee6520400a8757a05b..2f19afab53543ae7890613fe1c0246cbf8d858e1 100644 (file)
--- a/modules/http2/h2_session.c
+++ b/modules/http2/h2_session.c
@@ -171,6 +171,7 @@ static apr_status_t stream_schedule(h2_session *session,
                                     h2_stream *stream, int eos)
 {
     (void)session;
+    ++session->requests_received;
     return h2_stream_schedule(stream, eos, h2_session_push_enabled(session), 
                               stream_pri_cmp, session);
 }
@@ -441,6 +442,13 @@ static int on_frame_recv_cb(nghttp2_session *ng2s,
                           session->id, (int)frame->hd.stream_id,
                           frame->window_update.window_size_increment);
             break;
+        case NGHTTP2_RST_STREAM:
+            ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c,
+                          "h2_session(%ld-%d): RST_STREAM by client, errror=%d",
+                          session->id, (int)frame->hd.stream_id,
+                          (int)frame->rst_stream.error_code);
+            ++session->streams_reset;
+            break;
         default:
             if (APLOGctrace2(session->c)) {
                 char buffer[256];
@@ -1257,7 +1265,7 @@ static apr_status_t submit_response(h2_session *session, h2_stream *stream)
                                         response->headers);
         rv = nghttp2_submit_response(session->ngh2, response->stream_id,
                                      ngh->nv, ngh->nvlen, &provider);
-        
+        ++session->responses_sent;
     }
     else {
         int err = H2_STREAM_RST(stream, H2_ERR_PROTOCOL_ERROR);
@@ -1268,6 +1276,7 @@ static apr_status_t submit_response(h2_session *session, h2_stream *stream)
 
         rv = nghttp2_submit_rst_stream(session->ngh2, NGHTTP2_FLAG_NONE,
                                        stream->id, err);
+        ++session->responses_sent;
     }
     
     stream->submitted = 1;
@@ -1294,16 +1303,16 @@ struct h2_stream *h2_session_push(h2_session *session, h2_stream *is,
     ngh = h2_util_ngheader_make_req(is->pool, push->req);
     nid = nghttp2_submit_push_promise(session->ngh2, 0, is->id, 
                                       ngh->nv, ngh->nvlen, NULL);
-                                      
     if (nid <= 0) {
         ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c,
                       "h2_stream(%ld-%d): submitting push promise fail: %s",
                       session->id, is->id, nghttp2_strerror(nid));
         return NULL;
     }
-
+    ++session->streams_pushed;
+    
     ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c,
-                  "h2_stream(%ld-%d): promised new stream %d for %s %s on %d",
+                  "h2_stream(%ld-%d): SERVER_PUSH %d for %s %s on %d",
                   session->id, is->id, nid,
                   push->req->method, push->req->path, is->id);
                   
@@ -1594,11 +1603,12 @@ static apr_status_t h2_session_receive(void *ctx, const char *data,
     return APR_SUCCESS;
 }
 
-static apr_status_t h2_session_read(h2_session *session, int block)
+static apr_status_t h2_session_read(h2_session *session, int block, int loops)
 {
-    while (1) {
-        apr_status_t status;
-        
+    apr_status_t status, rstatus = APR_EAGAIN;
+    int i;
+    
+    for (i = 0; i < loops; ++i) {
         /* H2_IN filter handles all incoming data against the session.
          * We just pull at the filter chain to make it happen */
         status = ap_get_brigade(session->c->input_filters,
@@ -1612,38 +1622,48 @@ static apr_status_t h2_session_read(h2_session *session, int block)
             case APR_SUCCESS:
                 /* successful read, reset our idle timers */
                 session->wait_micros = 0;
+                rstatus = APR_SUCCESS;
                 if (block) {
-                    return APR_SUCCESS;
+                    /* successfull blocked read, try unblocked to
+                     * get more. */
+                    block = 0;
                 }
                 break;
             case APR_EAGAIN:
-                return status;
+                return rstatus;
             default:
-                if (APR_STATUS_IS_ETIMEDOUT(status)
-                    || APR_STATUS_IS_ECONNABORTED(status)
-                    || APR_STATUS_IS_ECONNRESET(status)
-                    || APR_STATUS_IS_EOF(status)
-                    || APR_STATUS_IS_EBADF(status)) {
-                    /* common status for a client that has left */
-                    ap_log_cerror( APLOG_MARK, APLOG_DEBUG, status, session->c,
-                                  "h2_session(%ld): terminating",
-                                  session->id);
-                    /* Stolen from mod_reqtimeout to speed up lingering when
-                     * a read timeout happened.
-                     */
-                    apr_table_setn(session->c->notes, "short-lingering-close", "1");
-                }
-                else {
-                    /* uncommon status, log on INFO so that we see this */
-                    ap_log_cerror( APLOG_MARK, APLOG_INFO, status, session->c,
-                                  APLOGNO(02950) 
-                                  "h2_session(%ld): error reading, terminating",
-                                  session->id);
+                if (!i) {
+                    /* first attempt failed */
+                    if (APR_STATUS_IS_ETIMEDOUT(status)
+                        || APR_STATUS_IS_ECONNABORTED(status)
+                        || APR_STATUS_IS_ECONNRESET(status)
+                        || APR_STATUS_IS_EOF(status)
+                        || APR_STATUS_IS_EBADF(status)) {
+                        /* common status for a client that has left */
+                        ap_log_cerror( APLOG_MARK, APLOG_DEBUG, status, session->c,
+                                      "h2_session(%ld): terminating",
+                                      session->id);
+                        /* Stolen from mod_reqtimeout to speed up lingering when
+                         * a read timeout happened.
+                         */
+                        apr_table_setn(session->c->notes, "short-lingering-close", "1");
+                    }
+                    else {
+                        /* uncommon status, log on INFO so that we see this */
+                        ap_log_cerror( APLOG_MARK, APLOG_INFO, status, session->c,
+                                      APLOGNO(02950) 
+                                      "h2_session(%ld): error reading, terminating",
+                                      session->id);
+                    }
+                    h2_session_abort(session, status, 0);
+                    return status;
                 }
-                h2_session_abort(session, status, 0);
-                return status;
+                /* subsequent failure after success(es), return initial
+                 * status. */
+                return rstatus;
         }
     }
+    return rstatus;
 }
 
 static apr_status_t h2_session_submit(h2_session *session)
@@ -1682,13 +1702,17 @@ apr_status_t h2_session_process(h2_session *session, int async)
 {
     apr_status_t status = APR_SUCCESS;
     int got_streams = 0;
-    int have_written = 0;
-    int have_read = 0;
+    int have_written, have_read;
+    int timeout_secs = session->timeout_secs;
+    int keep_alive = 0;
 
     ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
                   "h2_session(%ld): process", session->id);
 
     while (1) {
+        have_read = 0;
+        have_written = 0;
+ 
         if (session->aborted || (!nghttp2_session_want_read(session->ngh2)
                                  && !nghttp2_session_want_write(session->ngh2))) {
             ap_log_cerror( APLOG_MARK, APLOG_DEBUG, status, session->c,
@@ -1721,20 +1745,22 @@ apr_status_t h2_session_process(h2_session *session, int async)
 
         /* If we want client data, see if some is there. */
         if (nghttp2_session_want_read(session->ngh2)) {
-            int idle      = (session->frames_received > 2 && !got_streams);
+            int idle = (session->responses_sent && !got_streams);
             int may_block = ((session->frames_received <= 1) 
                              || idle
                              || (!h2_stream_set_has_unsubmitted(session->streams)
                                  && !h2_stream_set_has_suspended(session->streams)));
                                  
-            h2_filter_cin_timeout_set(session->cin, idle? session->keepalive_secs : session->timeout_secs);
-            status = h2_session_read(session, may_block && !async);
+            h2_filter_cin_timeout_set(session->cin, timeout_secs);
+            status = h2_session_read(session, may_block, 10);
             
+            got_streams = !h2_stream_set_is_empty(session->streams);
             ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
                           "h2_session(%ld): process -> read", session->id);
             if (status == APR_SUCCESS) {
                 have_read = 1;
-                got_streams = !h2_stream_set_is_empty(session->streams);
+                keep_alive = 0;
+                timeout_secs = session->timeout_secs;
                 if (session->reprioritize) {
                     ap_log_cerror( APLOG_MARK, APLOG_TRACE2, status, session->c,
                                   "h2_session(%ld): process -> reprioritize", session->id);
@@ -1743,26 +1769,46 @@ apr_status_t h2_session_process(h2_session *session, int async)
                 }
             }
             else if (status == APR_EAGAIN) {
-                /* FIXME: disabling this as event currently discards
-                 * connections on load when we return. */
-                if (async && may_block && 0) {
-                    /* There is nothing to read and we are in a state where we
-                     * have nothing to write until new input comes. Return to
-                     * our caller so that the MPM may schedule us again when
-                     * read seems possible.
-                     */
-                    ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
-                                  "h2_session(%ld): process -> BLOCK_READ, "
-                                  "frames_received=%d, got_streams=%d, "
-                                  "have_written=%d", 
-                                  session->id, (int)session->frames_received,
-                                  (int)got_streams, (int)have_written);
-                    h2_conn_io_flush(&session->io);
-                    if (session->c->cs) {
-                        session->c->cs->sense = CONN_SENSE_WANT_READ;
+                /* nothing to read */
+            }
+            else if (APR_STATUS_IS_TIMEUP(status)) {
+                if (may_block) {
+                    /* I think can only happen in mayblock... */
+                    if (async) {
+                        /* timeout reading, return to async MPM with our wish to 
+                         * read and let it handle that. It may just close the 
+                         * connection as it considers it in KEEPALIVE mode. */
+                        ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
+                                      "h2_session(%ld): 1st timeout, return to async "
+                                      "MPM for KEEPALIVE, frames_received=%d, "
+                                      "got_streams=%d, have_written=%d", 
+                                      session->id, (int)session->frames_received,
+                                      (int)got_streams, (int)have_written);
+                        if (session->c->cs) {
+                            session->c->cs->sense = CONN_SENSE_WANT_READ;
+                        }
+                        return APR_SUCCESS;
+                    } 
+                    else if (!keep_alive 
+                             && session->keepalive_secs > timeout_secs) {
+                        keep_alive = 1;
+                        timeout_secs = session->keepalive_secs - timeout_secs;
+                        ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
+                                      "h2_session(%ld): 1st timeout, set "
+                                      "keepalive timeout of + %d seconds", 
+                                      session->id, (int)timeout_secs);
+                        status = APR_EAGAIN;
+                    }
+                    else {
+                        /* fall thriough */
+                        ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,
+                                      "h2_session(%ld): keepalive expired, close", 
+                                      session->id);
                     }
-                    return APR_SUCCESS;
                 }
+                ap_log_cerror( APLOG_MARK, APLOG_DEBUG, status, session->c,
+                              "h2_session(%ld): timeout", session->id);
+                return status;
             }
             else {
                 ap_log_cerror( APLOG_MARK, APLOG_DEBUG, status, session->c,
@@ -1849,8 +1895,6 @@ apr_status_t h2_session_process(h2_session *session, int async)
         if (have_written) {
             h2_conn_io_flush(&session->io);
         }
-        have_written = 0;
-        have_read = 0;
     }
         
     ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, session->c,

diff --git a/modules/http2/h2_session.h b/modules/http2/h2_session.h
index 299e046c3757773cd037cc0e93ed51d7d5648858..b1542eddfd250f2096ed1ebda2bada04b2ed141b 100644 (file)
--- a/modules/http2/h2_session.h
+++ b/modules/http2/h2_session.h
@@ -76,16 +76,22 @@ struct h2_session {
                                      
     apr_size_t frames_received;     /* number of http/2 frames received */
     apr_size_t frames_sent;         /* number of http/2 frames sent */
+    int requests_received;          /* number of http/2 requests received */
+    int responses_sent;             /* number of http/2 responses submitted */
+    int streams_reset;              /* number of http/2 streams reset by client */
+    int streams_pushed;             /* number of http/2 streams pushed */
+    int max_stream_received;        /* highest stream id created */
+    int max_stream_handled;         /* highest stream id handled successfully */
+    
     apr_size_t max_stream_count;    /* max number of open streams */
     apr_size_t max_stream_mem;      /* max buffer memory for a single stream */
+    int timeout_secs;               /* connection timeout (seconds) */
+    int keepalive_secs;             /* connection idle timeout (seconds) */
     
     apr_pool_t *pool;               /* pool to use in session handling */
     apr_bucket_brigade *bbtmp;      /* brigade for keeping temporary data */
     struct apr_thread_cond_t *iowait; /* our cond when trywaiting for data */
     
-    int timeout_secs;               /* connection timeout (seconds) */
-    int keepalive_secs;             /* connection idle timeout (seconds) */
-    
     struct h2_filter_cin *cin;      /* connection input filter context */
     h2_conn_io io;                  /* io on httpd conn filters */
 
@@ -94,9 +100,6 @@ struct h2_session {
     struct h2_stream *last_stream;  /* last stream worked with */
     struct h2_stream_set *streams;  /* streams handled by this session */
     
-    int max_stream_received;        /* highest stream id created */
-    int max_stream_handled;         /* highest stream id handled successfully */
-    
     apr_pool_t *spare;              /* spare stream pool */
     
     struct nghttp2_session *ngh2;   /* the nghttp2 session (internal use) */