mod_proxy_http2: rescheduling of requests not processed by backend on GOAWAY

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

CHANGES

@@ -1,6 +1,10 @@
                                                          -*- coding: utf-8 -*-
 Changes with Apache 2.5.0
 
+  *) mod_proxy_http2: rescheduling of requests that have not been processed
+     by the backend when receiving a GOAWAY frame before done.
+     [Stefan Eissign]
+     
   *) mod_reqtimeout: Prevent long response times from triggering a timeout once
      the request has been fully read.  PR 59045.  [Yann Ylavic]
 

modules/http2/h2_ngn_shed.c

@@ -164,7 +164,9 @@ apr_status_t h2_ngn_shed_push_req(h2_ngn_shed *shed, const char *ngn_type,
         ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, task->c,
                       "h2_ngn_shed(%ld): pushing request %s to %s", 
                       shed->c->id, task->id, ngn->id);
-        h2_task_freeze(task, r);
+        if (!h2_task_is_detached(task)) {
+            h2_task_freeze(task, r);
+        }
         /* FIXME: sometimes ngn is garbage, probly alread freed */
         ngn_add_req(ngn, task, r);
         ngn->no_assigned++;

modules/http2/h2_proxy_session.c

@@ -155,6 +155,9 @@ static int on_frame_recv(nghttp2_session *ngh2, const nghttp2_frame *frame,
             }
             break;
         case NGHTTP2_GOAWAY:
+            /* we expect the remote server to tell us the highest stream id
+             * that it has started processing. */
+            session->last_stream_id = frame->goaway.last_stream_id;
             dispatch_event(session, H2_PROXYS_EV_REMOTE_GOAWAY, 0, NULL);
             if (APLOGcinfo(session->c)) {
                 char buffer[256];
@@ -1057,7 +1060,7 @@ static void ev_stream_done(h2_proxy_session *session, int stream_id,
         h2_ihash_remove(session->streams, stream_id);
         h2_iq_remove(session->suspended, stream_id);
         if (session->done) {
-            session->done(session, stream->r);
+            session->done(session, stream->r, 1, 1);
         }
     }
     
@@ -1279,11 +1282,12 @@ typedef struct {
     h2_proxy_request_done *done;
 } cleanup_iter_ctx;
 
-static int cleanup_iter(void *udata, void *val)
+static int done_iter(void *udata, void *val)
 {
     cleanup_iter_ctx *ctx = udata;
     h2_proxy_stream *stream = val;
-    ctx->done(ctx->session, stream->r);
+    int touched = (stream->id <= ctx->session->last_stream_id);
+    ctx->done(ctx->session, stream->r, 0, touched);
     return 1;
 }
 
@@ -1294,10 +1298,10 @@ void h2_proxy_session_cleanup(h2_proxy_session *session,
         cleanup_iter_ctx ctx;
         ctx.session = session;
         ctx.done = done;
-        ap_log_cerror(APLOG_MARK, APLOG_WARNING, 0, session->c, 
+        ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, 
                       "h2_proxy_session(%s): terminated, %d streams unfinished",
                       session->id, (int)h2_ihash_count(session->streams));
-        h2_ihash_iter(session->streams, cleanup_iter, &ctx);
+        h2_ihash_iter(session->streams, done_iter, &ctx);
         h2_ihash_clear(session->streams);
     }
 }

modules/http2/h2_proxy_session.h

@@ -51,7 +51,8 @@ typedef enum {
 
 
 typedef struct h2_proxy_session h2_proxy_session;
-typedef void h2_proxy_request_done(h2_proxy_session *s, request_rec *r);
+typedef void h2_proxy_request_done(h2_proxy_session *s, request_rec *r,
+                                   int complete, int touched);
 
 struct h2_proxy_session {
     const char *id;
@@ -75,7 +76,7 @@ struct h2_proxy_session {
     struct h2_ihash_t *streams;
     struct h2_int_queue *suspended;
     apr_size_t remote_max_concurrent;
-    int max_stream_recv;
+    int last_stream_id;     /* last stream id processed by backend, or 0 */
     
     apr_bucket_brigade *input;
     apr_bucket_brigade *output;

modules/http2/h2_task.c

@@ -335,6 +335,11 @@ apr_status_t h2_task_thaw(h2_task *task)
         ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, task->c, 
                       "h2_task(%s), thawed", task->id);
     }
+    task->detached = 1;
     return APR_SUCCESS;
 }
 
+int h2_task_is_detached(h2_task *task)
+{
+    return task->detached;
+}

modules/http2/h2_task.h

@@ -60,6 +60,7 @@ struct h2_task {
     unsigned int ser_headers : 1;
     unsigned int frozen      : 1;
     unsigned int blocking    : 1;
+    unsigned int detached    : 1;
     
     struct h2_task_input *input;
     struct h2_task_output *output;
@@ -84,6 +85,7 @@ extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_task_logio_add_bytes_out
 
 apr_status_t h2_task_freeze(h2_task *task, request_rec *r);
 apr_status_t h2_task_thaw(h2_task *task);
+int h2_task_is_detached(h2_task *task);
 
 void h2_task_set_io_blocking(h2_task *task, int blocking);
 

modules/http2/h2_util.c

@@ -309,12 +309,12 @@ static int ihash_iter(void *ctx, const void *key, apr_ssize_t klen,
     return ictx->iter(ictx->ctx, (void*)val); /* why is this passed const?*/
 }
 
-void h2_ihash_iter(h2_ihash_t *ih, h2_ihash_iter_t *fn, void *ctx)
+int h2_ihash_iter(h2_ihash_t *ih, h2_ihash_iter_t *fn, void *ctx)
 {
     iter_ctx ictx;
     ictx.iter = fn;
     ictx.ctx = ctx;
-    apr_hash_do(ihash_iter, &ictx, ih->hash);
+    return apr_hash_do(ihash_iter, &ictx, ih->hash);
 }
 
 void h2_ihash_add(h2_ihash_t *ih, void *val)
@@ -1212,8 +1212,9 @@ int h2_util_frame_print(const nghttp2_frame *frame, char *buffer, size_t maxlen)
             frame->goaway.opaque_data_len : s_len-1;
             memcpy(scratch, frame->goaway.opaque_data, len);
             scratch[len] = '\0';
-            return apr_snprintf(buffer, maxlen, "GOAWAY[error=%d, reason='%s']",
+            return apr_snprintf(buffer, maxlen, "GOAWAY[error=%d, reason='%s', "
-                                frame->goaway.error_code, scratch);
+                                "last_stream=%d]", frame->goaway.error_code, 
+                                scratch, frame->goaway.last_stream_id);
         }
         case NGHTTP2_WINDOW_UPDATE: {
             return apr_snprintf(buffer, maxlen,

modules/http2/h2_util.h

@@ -56,8 +56,9 @@ void *h2_ihash_get(h2_ihash_t *ih, int id);
  * @param ih the hash to iterate over
  * @param fn the function to invoke on each member
  * @param ctx user supplied data passed into each iteration call
+ * @param 0 if one iteration returned 0, otherwise != 0
  */
-void h2_ihash_iter(h2_ihash_t *ih, h2_ihash_iter_t *fn, void *ctx);
+int h2_ihash_iter(h2_ihash_t *ih, h2_ihash_iter_t *fn, void *ctx);
 
 void h2_ihash_add(h2_ihash_t *ih, void *val);
 void h2_ihash_remove(h2_ihash_t *ih, int id);

modules/http2/mod_proxy_http2.c

@@ -239,21 +239,46 @@ static apr_status_t add_request(h2_proxy_session *session, request_rec *r)
     return status;
 }
 
-static void request_done(h2_proxy_session *session, request_rec *r)
+static void request_done(h2_proxy_session *session, request_rec *r,
+                         int complete, int touched)
 {   
     h2_proxy_ctx *ctx = session->user_data;
+    const char *task_id = apr_table_get(r->connection->notes, H2_TASK_ID_NOTE);
     
-    if (r == ctx->rbase) {
+    if (!complete && !touched) {
+        /* untouched request, need rescheduling */
+        if (req_engine_push && is_h2 && is_h2(ctx->owner)) {
+            if (req_engine_push(ctx->engine_type, r, NULL) == APR_SUCCESS) {
+                /* push to engine */
+                ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, r->connection, 
+                              "h2_proxy_session(%s): rescheduled request %s",
+                              ctx->engine_id, task_id);
+                return;
+            }
+        }
+    }
+    
+    if (r == ctx->rbase && complete) {
         ctx->r_status = APR_SUCCESS;
     }
     
-    if (req_engine_done && ctx->engine) {
+    if (complete) {
-        ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, r->connection, 
+        if (req_engine_done && ctx->engine) {
-                      "h2_proxy_session(%s): request %s",
+            ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, r->connection, 
-                      ctx->engine_id, r->the_request);
+                          "h2_proxy_session(%s): finished request %s",
-        req_engine_done(ctx->engine, r->connection);
+                          ctx->engine_id, task_id);
+            req_engine_done(ctx->engine, r->connection);
+        }
     }
-}
+    else {
+        if (req_engine_done && ctx->engine) {
+            ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, r->connection, 
+                          "h2_proxy_session(%s): failed request %s",
+                          ctx->engine_id, task_id);
+            req_engine_done(ctx->engine, r->connection);
+        }
+    }
+}    
 
 static apr_status_t next_request(h2_proxy_ctx *ctx, int before_leave)
 {
@@ -404,7 +429,8 @@ static int proxy_http2_handler(request_rec *r,
     apr_pool_t *p = c->pool;
     apr_uri_t *uri = apr_palloc(p, sizeof(*uri));
     h2_proxy_ctx *ctx;
-
+    int reconnected = 0;
+    
     /* find the scheme */
     if ((url[0] != 'h' && url[0] != 'H') || url[1] != '2') {
        return DECLINED;
@@ -531,7 +557,7 @@ run_session:
     }
 
 cleanup:
-    if (ctx->engine && next_request(ctx, 1) == APR_SUCCESS) {
+    if (!reconnected && ctx->engine && next_request(ctx, 1) == APR_SUCCESS) {
         /* Still more to do, tear down old conn and start over */
         if (ctx->p_conn) {
             ctx->p_conn->close = 1;
@@ -539,6 +565,7 @@ cleanup:
             ap_proxy_release_connection(ctx->proxy_func, ctx->p_conn, ctx->server);
             ctx->p_conn = NULL;
         }
+        reconnected = 1; /* we do this only once, then fail */
         goto run_connect;
     }