From 1e4eee5260f3bfb16dd750308eb2e296fd8b395c Mon Sep 17 00:00:00 2001 From: Stefan Eissing Date: Wed, 27 Jan 2016 17:39:22 +0100 Subject: [PATCH] timeouts for hanging requests, event mpm fixes --- ChangeLog | 7 +++ configure.ac | 2 +- mod_http2/h2_conn.c | 24 +++++++++ mod_http2/h2_session.c | 107 ++++++++++++++++++++++++++++------------- mod_http2/h2_session.h | 4 +- mod_http2/h2_version.h | 4 +- 6 files changed, 110 insertions(+), 38 deletions(-) diff --git a/ChangeLog b/ChangeLog index 4a5af3f6..b23c68d9 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,10 @@ +v1.2.3 +-------------------------------------------------------------------------------- + * connection timeout handling when requests do not report back + * setting correct server config for event mpm on main connection, so that + timeouts, keepalives use the correct values + * fixes event hack to match changes in structures + v1.2.2 -------------------------------------------------------------------------------- * removed unused code diff --git a/configure.ac b/configure.ac index 1fda0708..3af816fc 100644 --- a/configure.ac +++ b/configure.ac @@ -14,7 +14,7 @@ # AC_PREREQ([2.69]) -AC_INIT([mod_http2], [1.2.2], [stefan.eissing@greenbytes.de]) +AC_INIT([mod_http2], [1.2.3], [stefan.eissing@greenbytes.de]) LT_PREREQ([2.2.6]) LT_INIT() diff --git a/mod_http2/h2_conn.c b/mod_http2/h2_conn.c index 3e762f16..3de14736 100644 --- a/mod_http2/h2_conn.c +++ b/mod_http2/h2_conn.c @@ -75,6 +75,8 @@ static void check_modules(int force) } } +static void fix_event_master_conn(h2_session *session); + apr_status_t h2_conn_child_init(apr_pool_t *pool, server_rec *s) { const h2_config *config = h2_config_sget(s); @@ -168,6 +170,15 @@ apr_status_t h2_conn_setup(h2_ctx *ctx, conn_rec *c, request_rec *r) } h2_ctx_session_set(ctx, session); + + switch (h2_conn_mpm_type()) { + case H2_MPM_EVENT: + fix_event_master_conn(session); + break; + default: + break; + } + return APR_SUCCESS; } @@ -292,6 +303,8 @@ struct event_conn_state_t { conn_rec *c; /** request record (if any) this struct refers to */ request_rec *r; + /** server config this struct refers to */ + void *sc; /** is the current conn_rec suspended? (disassociated with * a particular MPM thread; for suspend_/resume_connection * hooks) @@ -327,3 +340,14 @@ static void fix_event_conn(conn_rec *c, conn_rec *master) c->cs = &(cs->pub); } +static void fix_event_master_conn(h2_session *session) +{ + /* TODO: event MPM normally does this in a post_read_request hook. But + * we never encounter that on our master connection. We *do* know which + * server was selected during protocol negotiation, so lets set that. + */ + event_conn_state_t *cs = ap_get_module_config(session->c->conn_config, + h2_conn_mpm_module()); + cs->sc = ap_get_module_config(session->s->module_config, h2_conn_mpm_module()); +} + diff --git a/mod_http2/h2_session.c b/mod_http2/h2_session.c index 34575a6b..8d75e95c 100644 --- a/mod_http2/h2_session.c +++ b/mod_http2/h2_session.c @@ -18,6 +18,8 @@ #include #include +#include + #include #include #include @@ -1534,8 +1536,9 @@ static int frame_print(const nghttp2_frame *frame, char *buffer, size_t maxlen) } case NGHTTP2_WINDOW_UPDATE: { return apr_snprintf(buffer, maxlen, - "WINDOW_UPDATE[length=%d, stream=%d]", - (int)frame->hd.length, frame->hd.stream_id); + "WINDOW_UPDATE[stream=%d, incr=%d]", + frame->hd.stream_id, + frame->window_update.window_size_increment); } default: return apr_snprintf(buffer, maxlen, @@ -1823,15 +1826,26 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) { switch (session->state) { case H2_SESSION_ST_BUSY: + case H2_SESSION_ST_LOCAL_SHUTDOWN: + case H2_SESSION_ST_REMOTE_SHUTDOWN: /* nothing for input and output to do. If we remain * in this state, we go into a tight loop and suck up * CPU cycles. Ideally, we'd like to do a blocking read, but that * is not possible if we have scheduled tasks and wait * for them to produce something. */ if (h2_stream_set_is_empty(session->streams)) { - /* When we have no streams, no task event are possible, - * switch to blocking reads */ - transit(session, "no io", H2_SESSION_ST_IDLE); + if (!is_accepting_streams(session)) { + /* We are no longer accepting new streams and have + * finished processing existing ones. Time to leave. */ + h2_session_shutdown(session, arg, msg); + transit(session, "no io", H2_SESSION_ST_DONE); + } + else { + /* When we have no streams, no task event are possible, + * switch to blocking reads */ + transit(session, "no io", H2_SESSION_ST_IDLE); + session->keepalive_remain = session->keepalive_secs; + } } else if (!h2_stream_set_has_unsubmitted(session->streams) && !h2_stream_set_has_suspended(session->streams)) { @@ -1839,6 +1853,7 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) * new output data from task processing, * switch to blocking reads. */ transit(session, "no io", H2_SESSION_ST_IDLE); + session->keepalive_remain = session->keepalive_secs; } else { /* Unable to do blocking reads, as we wait on events from @@ -1853,18 +1868,6 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) } } -static void h2_session_ev_wait_timeout(h2_session *session, int arg, const char *msg) -{ - switch (session->state) { - case H2_SESSION_ST_WAIT: - transit(session, "wait timeout", H2_SESSION_ST_BUSY); - break; - default: - /* nop */ - break; - } -} - static void h2_session_ev_stream_ready(h2_session *session, int arg, const char *msg) { switch (session->state) { @@ -1902,6 +1905,19 @@ static void h2_session_ev_ngh2_done(h2_session *session, int arg, const char *ms } } +static void h2_session_ev_mpm_stopping(h2_session *session, int arg, const char *msg) +{ + switch (session->state) { + case H2_SESSION_ST_DONE: + case H2_SESSION_ST_LOCAL_SHUTDOWN: + /* nop */ + break; + default: + h2_session_shutdown(session, arg, msg); + break; + } +} + static void dispatch_event(h2_session *session, h2_session_event_t ev, int arg, const char *msg) { @@ -1927,9 +1943,6 @@ static void dispatch_event(h2_session *session, h2_session_event_t ev, case H2_SESSION_EV_NO_IO: h2_session_ev_no_io(session, arg, msg); break; - case H2_SESSION_EV_WAIT_TIMEOUT: - h2_session_ev_wait_timeout(session, arg, msg); - break; case H2_SESSION_EV_STREAM_READY: h2_session_ev_stream_ready(session, arg, msg); break; @@ -1939,6 +1952,9 @@ static void dispatch_event(h2_session *session, h2_session_event_t ev, case H2_SESSION_EV_NGH2_DONE: h2_session_ev_ngh2_done(session, arg, msg); break; + case H2_SESSION_EV_MPM_STOPPING: + h2_session_ev_mpm_stopping(session, arg, msg); + break; default: ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, session->c, "h2_session(%ld): unknown event %d", @@ -1957,14 +1973,25 @@ apr_status_t h2_session_process(h2_session *session, int async) { apr_status_t status = APR_SUCCESS; conn_rec *c = session->c; - int rv, have_written, have_read; + int rv, have_written, have_read, mpm_state; ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, c, "h2_session(%ld): process start, async=%d", session->id, async); + if (c->cs) { + c->cs->state = CONN_STATE_WRITE_COMPLETION; + } + while (1) { have_read = have_written = 0; + if (!ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state)) { + if (mpm_state == AP_MPMQ_STOPPING) { + dispatch_event(session, H2_SESSION_EV_MPM_STOPPING, 0, NULL); + break; + } + } + switch (session->state) { case H2_SESSION_ST_INIT: if (!h2_is_acceptable_connection(c, 1)) { @@ -1986,7 +2013,6 @@ apr_status_t h2_session_process(h2_session *session, int async) case H2_SESSION_ST_IDLE: h2_filter_cin_timeout_set(session->cin, session->keepalive_secs); - ap_update_child_status(c->sbh, SERVER_BUSY_KEEPALIVE, NULL); status = h2_session_read(session, 1, 10); if (status == APR_SUCCESS) { have_read = 1; @@ -1996,8 +2022,7 @@ apr_status_t h2_session_process(h2_session *session, int async) /* nothing to read */ } else if (APR_STATUS_IS_TIMEUP(status)) { - dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, 0, NULL); - break; + dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, 0, "timeout"); } else { dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); @@ -2062,32 +2087,46 @@ apr_status_t h2_session_process(h2_session *session, int async) } if (have_read || have_written) { - session->wait_us = 0; + if (session->wait_us) { + session->wait_us = 0; + } } - else { + else if (!nghttp2_session_want_write(session->ngh2)) { dispatch_event(session, H2_SESSION_EV_NO_IO, 0, NULL); } break; case H2_SESSION_ST_WAIT: - session->wait_us = H2MAX(session->wait_us, 10); + if (session->wait_us <= 0) { + session->wait_us = 10; + session->start_wait = apr_time_now(); + } + else if (apr_time_sec(apr_time_now() - session->start_wait) + >= session->timeout_secs) { + /* waited long enough */ + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, APR_TIMEUP, c, + "h2_session: wait for data"); + dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, 0, "timeout"); + } + else { + /* repeating, increase timer for graceful backoff */ + session->wait_us = H2MIN(session->wait_us*2, MAX_WAIT_MICROS); + } + if (APLOGctrace1(c)) { ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c, "h2_session: wait for data, %ld micros", (long)session->wait_us); } - - ap_log_cerror( APLOG_MARK, APLOG_TRACE2, status, c, - "h2_session(%ld): process -> trywait", session->id); status = h2_mplx_out_trywait(session->mplx, session->wait_us, session->iowait); if (status == APR_SUCCESS) { - dispatch_event(session, H2_SESSION_EV_STREAM_READY, 0, NULL); + session->wait_us = 0; + dispatch_event(session, H2_SESSION_EV_DATA_READ, 0, NULL); } else if (status == APR_TIMEUP) { - /* nothing, increase timer for graceful backup */ - session->wait_us = H2MIN(session->wait_us*2, MAX_WAIT_MICROS); - dispatch_event(session, H2_SESSION_EV_WAIT_TIMEOUT, 0, NULL); + /* go back to checking all inputs again */ + transit(session, "wait cycle", H2_SESSION_ST_BUSY); } else { h2_session_shutdown(session, H2_ERR_INTERNAL_ERROR, "cond wait error"); diff --git a/mod_http2/h2_session.h b/mod_http2/h2_session.h index 17a4ec5a..084961da 100644 --- a/mod_http2/h2_session.h +++ b/mod_http2/h2_session.h @@ -72,10 +72,10 @@ typedef enum { H2_SESSION_EV_PROTO_ERROR, /* protocol error */ H2_SESSION_EV_CONN_TIMEOUT, /* connection timeout */ H2_SESSION_EV_NO_IO, /* nothing has been read or written */ - H2_SESSION_EV_WAIT_TIMEOUT, /* timeout waiting for tasks */ H2_SESSION_EV_STREAM_READY, /* stream signalled availability of headers/data */ H2_SESSION_EV_DATA_READ, /* connection data has been read */ H2_SESSION_EV_NGH2_DONE, /* nghttp2 wants neither read nor write anything */ + H2_SESSION_EV_MPM_STOPPING, /* the process is stopping */ } h2_session_event_t; typedef struct h2_session { @@ -110,6 +110,8 @@ typedef struct h2_session { 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 keepalive_remain; /* remaining seconds of keepalive */ + apr_time_t start_wait; /* Time we started waiting for sth. to happen */ int timeout_secs; /* connection timeout (seconds) */ int keepalive_secs; /* connection idle timeout (seconds) */ diff --git a/mod_http2/h2_version.h b/mod_http2/h2_version.h index aa42109e..a85f640a 100644 --- a/mod_http2/h2_version.h +++ b/mod_http2/h2_version.h @@ -26,7 +26,7 @@ * @macro * Version number of the http2 module as c string */ -#define MOD_HTTP2_VERSION "1.2.2" +#define MOD_HTTP2_VERSION "1.2.3" /** * @macro @@ -34,7 +34,7 @@ * release. This is a 24 bit number with 8 bits for major number, 8 bits * for minor and 8 bits for patch. Version 1.2.3 becomes 0x010203. */ -#define MOD_HTTP2_VERSION_NUM 0x010202 +#define MOD_HTTP2_VERSION_NUM 0x010203 #endif /* mod_h2_h2_version_h */