From: Stefan Eissing Date: Mon, 6 Dec 2021 10:34:27 +0000 (+0000) Subject: *) mod_http2: fixed a bug in v2.0.0 that could lead to an infinite X-Git-Tag: 2.5.0-alpha2-ci-test-only~662 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=1598f7aebd59acc7494389a3903a33c5e38a5460;p=thirdparty%2Fapache%2Fhttpd.git *) mod_http2: fixed a bug in v2.0.0 that could lead to an infinite loop when clients close connections prematurely. Enhanced the scoreboard status updates on h2 connections for mod_status. 'server-status' now gives a better idea what the connection is working on. git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1895614 13f79535-47bb-0310-9956-ffa450edef68 --- diff --git a/changes-entries/http2_2.0.1.txt b/changes-entries/http2_2.0.1.txt new file mode 100644 index 00000000000..9ae23f20cff --- /dev/null +++ b/changes-entries/http2_2.0.1.txt @@ -0,0 +1,6 @@ + *) mod_http2: fixed a bug in v2.0.0 that could lead to an infinite + loop when clients close connections prematurely. + Enhanced the scoreboard status updates on h2 connections for + mod_status. 'server-status' now gives a better idea what the + connection is working on. + [Stefan Eissing] \ No newline at end of file diff --git a/modules/http2/h2.h b/modules/http2/h2.h index e5a837c7281..47d830a297d 100644 --- a/modules/http2/h2.h +++ b/modules/http2/h2.h @@ -114,6 +114,7 @@ typedef struct h2_session_props { int emitted_count; /* the number of local streams sent */ int emitted_max; /* the highest local stream id sent */ int error; /* the last session error encountered */ + const char *error_msg; /* the short message given on the error */ unsigned int accepting : 1; /* if the session is accepting new streams */ unsigned int shutdown : 1; /* if the final GOAWAY has been sent */ } h2_session_props; diff --git a/modules/http2/h2_c1.c b/modules/http2/h2_c1.c index 834b6a9745c..5be7e907e4a 100644 --- a/modules/http2/h2_c1.c +++ b/modules/http2/h2_c1.c @@ -50,6 +50,9 @@ static struct h2_workers *workers; static int async_mpm; +APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_c_logio_add_bytes_in; +APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_c_logio_add_bytes_out; + apr_status_t h2_c1_child_init(apr_pool_t *pool, server_rec *s) { apr_status_t status = APR_SUCCESS; @@ -75,6 +78,9 @@ apr_status_t h2_c1_child_init(apr_pool_t *pool, server_rec *s) minw, maxw, max_threads_per_child, idle_secs); workers = h2_workers_create(s, pool, minw, maxw, idle_secs); + h2_c_logio_add_bytes_in = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_in); + h2_c_logio_add_bytes_out = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_out); + return h2_mplx_c1_child_init(pool, s); } diff --git a/modules/http2/h2_c1.h b/modules/http2/h2_c1.h index 232c71c3018..41527f6da5c 100644 --- a/modules/http2/h2_c1.h +++ b/modules/http2/h2_c1.h @@ -17,8 +17,13 @@ #ifndef __mod_h2__h2_c1__ #define __mod_h2__h2_c1__ +#include + struct h2_conn_ctx_t; +extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_c_logio_add_bytes_in; +extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_c_logio_add_bytes_out; + /* Initialize this child process for h2 primary connection work, * to be called once during child init before multi processing * starts. diff --git a/modules/http2/h2_c1_io.c b/modules/http2/h2_c1_io.c index 3cd6ae62044..2300c612018 100644 --- a/modules/http2/h2_c1_io.c +++ b/modules/http2/h2_c1_io.c @@ -30,6 +30,7 @@ #include "h2_private.h" #include "h2_bucket_eos.h" #include "h2_config.h" +#include "h2_c1.h" #include "h2_c1_io.h" #include "h2_protocol.h" #include "h2_session.h" @@ -137,35 +138,37 @@ static void h2_c1_io_bb_log(conn_rec *c, int stream_id, int level, } -apr_status_t h2_c1_io_init(h2_c1_io *io, conn_rec *c, server_rec *s) +apr_status_t h2_c1_io_init(h2_c1_io *io, h2_session *session) { - io->c = c; - io->output = apr_brigade_create(c->pool, c->bucket_alloc); - io->is_tls = ap_ssl_conn_is_ssl(c); + conn_rec *c = session->c1; + + io->session = session; + io->output = apr_brigade_create(c->pool, c->bucket_alloc); + io->is_tls = ap_ssl_conn_is_ssl(session->c1); io->buffer_output = io->is_tls; - io->flush_threshold = 4 * (apr_size_t)h2_config_sgeti64(s, H2_CONF_STREAM_MAX_MEM); + io->flush_threshold = 4 * (apr_size_t)h2_config_sgeti64(session->s, H2_CONF_STREAM_MAX_MEM); if (io->buffer_output) { /* This is what we start with, * see https://issues.apache.org/jira/browse/TS-2503 */ - io->warmup_size = h2_config_sgeti64(s, H2_CONF_TLS_WARMUP_SIZE); - io->cooldown_usecs = (h2_config_sgeti(s, H2_CONF_TLS_COOLDOWN_SECS) + io->warmup_size = h2_config_sgeti64(session->s, H2_CONF_TLS_WARMUP_SIZE); + io->cooldown_usecs = (h2_config_sgeti(session->s, H2_CONF_TLS_COOLDOWN_SECS) * APR_USEC_PER_SEC); io->cooldown_usecs = 0; - io->write_size = (io->cooldown_usecs > 0? - WRITE_SIZE_INITIAL : WRITE_SIZE_MAX); + io->write_size = (io->cooldown_usecs > 0? + WRITE_SIZE_INITIAL : WRITE_SIZE_MAX); } else { - io->warmup_size = 0; + io->warmup_size = 0; io->cooldown_usecs = 0; - io->write_size = 0; + io->write_size = 0; } if (APLOGctrace1(c)) { - ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, io->c, + ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, c, "h2_c1_io(%ld): init, buffering=%d, warmup_size=%ld, " - "cd_secs=%f", io->c->id, io->buffer_output, + "cd_secs=%f", c->id, io->buffer_output, (long)io->warmup_size, ((double)io->cooldown_usecs/APR_USEC_PER_SEC)); } @@ -178,7 +181,7 @@ static void append_scratch(h2_c1_io *io) if (io->scratch && io->slen > 0) { apr_bucket *b = apr_bucket_heap_create(io->scratch, io->slen, apr_bucket_free, - io->c->bucket_alloc); + io->session->c1->bucket_alloc); APR_BRIGADE_INSERT_TAIL(io->output, b); io->buffered_len += io->slen; io->scratch = NULL; @@ -194,7 +197,7 @@ static apr_size_t assure_scratch_space(h2_c1_io *io) { if (!io->scratch) { /* we control the size and it is larger than what buckets usually * allocate. */ - io->scratch = apr_bucket_alloc(io->write_size, io->c->bucket_alloc); + io->scratch = apr_bucket_alloc(io->write_size, io->session->c1->bucket_alloc); io->ssize = io->write_size; io->slen = 0; remain = io->ssize; @@ -235,9 +238,9 @@ static apr_status_t read_to_scratch(h2_c1_io *io, apr_bucket *b) io->slen += len; } else if (APR_BUCKET_IS_MMAP(b)) { - ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, io->c, + ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, io->session->c1, "h2_c1_io(%ld): seeing mmap bucket of size %ld, scratch remain=%ld", - io->c->id, (long)b->length, (long)(io->ssize - io->slen)); + io->session->c1->id, (long)b->length, (long)(io->ssize - io->slen)); status = apr_bucket_read(b, &data, &len, APR_BLOCK_READ); if (status == APR_SUCCESS) { memcpy(io->scratch+io->slen, data, len); @@ -256,14 +259,14 @@ static apr_status_t read_to_scratch(h2_c1_io *io, apr_bucket *b) static apr_status_t pass_output(h2_c1_io *io, int flush) { - conn_rec *c = io->c; + conn_rec *c = io->session->c1; apr_off_t bblen; apr_status_t rv; append_scratch(io); if (flush) { if (!APR_BUCKET_IS_FLUSH(APR_BRIGADE_LAST(io->output))) { - apr_bucket *b = apr_bucket_flush_create(io->c->bucket_alloc); + apr_bucket *b = apr_bucket_flush_create(c->bucket_alloc); APR_BRIGADE_INSERT_TAIL(io->output, b); } } @@ -271,7 +274,6 @@ static apr_status_t pass_output(h2_c1_io *io, int flush) return APR_SUCCESS; } - ap_update_child_status(c->sbh, SERVER_BUSY_WRITE, NULL); io->unflushed = !APR_BUCKET_IS_FLUSH(APR_BRIGADE_LAST(io->output)); apr_brigade_length(io->output, 0, &bblen); C1_IO_BB_LOG(c, 0, APLOG_TRACE2, "out", io->output); @@ -281,6 +283,7 @@ static apr_status_t pass_output(h2_c1_io *io, int flush) io->buffered_len = 0; io->bytes_written += (apr_size_t)bblen; + if (io->write_size < WRITE_SIZE_MAX && io->bytes_written >= io->warmup_size) { /* connection is hot, use max size */ @@ -346,9 +349,9 @@ apr_status_t h2_c1_io_add_data(h2_c1_io *io, const char *data, size_t length) apr_status_t status = APR_SUCCESS; apr_size_t remain; - ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, io->c, + ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, io->session->c1, "h2_c1_io(%ld): adding %ld data bytes", - io->c->id, (long)length); + io->session->c1->id, (long)length); if (io->buffer_output) { while (length > 0) { remain = assure_scratch_space(io); @@ -408,7 +411,7 @@ apr_status_t h2_c1_io_append(h2_c1_io *io, apr_bucket_brigade *bb) } else { /* no buffering, forward buckets setaside on flush */ - apr_bucket_setaside(b, io->c->pool); + apr_bucket_setaside(b, io->session->c1->pool); APR_BUCKET_REMOVE(b); APR_BRIGADE_INSERT_TAIL(io->output, b); io->buffered_len += b->length; diff --git a/modules/http2/h2_c1_io.h b/modules/http2/h2_c1_io.h index 95088eac7eb..d891ffb44df 100644 --- a/modules/http2/h2_c1_io.h +++ b/modules/http2/h2_c1_io.h @@ -27,7 +27,7 @@ struct h2_session; * directly without copying. */ typedef struct { - conn_rec *c; + struct h2_session *session; apr_bucket_brigade *output; int is_tls; @@ -50,7 +50,7 @@ typedef struct { apr_size_t slen; } h2_c1_io; -apr_status_t h2_c1_io_init(h2_c1_io *io, conn_rec *c, server_rec *s); +apr_status_t h2_c1_io_init(h2_c1_io *io, struct h2_session *session); /** * Append data to the buffered output. diff --git a/modules/http2/h2_c2.c b/modules/http2/h2_c2.c index dd2e10b3214..4e689c7c11c 100644 --- a/modules/http2/h2_c2.c +++ b/modules/http2/h2_c2.c @@ -342,9 +342,9 @@ receive: h2_util_bb_log(f->c, conn_ctx->stream_id, APLOG_TRACE2, "c2 input recv raw", fctx->bb); } - if (h2_c2_logio_add_bytes_in) { + if (h2_c_logio_add_bytes_in) { apr_brigade_length(bb, 0, &bblen); - h2_c2_logio_add_bytes_in(f->c, bblen); + h2_c_logio_add_bytes_in(f->c, bblen); } } @@ -419,7 +419,7 @@ static apr_status_t beam_out(conn_rec *c2, h2_conn_ctx_t *conn_ctx, apr_bucket_b apr_off_t written, header_len = 0; apr_status_t rv; - if (h2_c2_logio_add_bytes_out) { + if (h2_c_logio_add_bytes_out) { /* mod_logio wants to report the number of bytes written in a * response, including header and footer fields. Since h2 converts * those during c1 processing into the HPACKed h2 HEADER frames, @@ -440,8 +440,8 @@ static apr_status_t beam_out(conn_rec *c2, h2_conn_ctx_t *conn_ctx, apr_bucket_b if (APR_STATUS_IS_EAGAIN(rv)) { rv = APR_SUCCESS; } - if (written && h2_c2_logio_add_bytes_out) { - h2_c2_logio_add_bytes_out(c2, written + header_len); + if (written && h2_c_logio_add_bytes_out) { + h2_c_logio_add_bytes_out(c2, written + header_len); } return rv; } @@ -466,15 +466,6 @@ static apr_status_t h2_c2_filter_out(ap_filter_t* f, apr_bucket_brigade* bb) return rv; } -/* post config init */ -apr_status_t h2_c2_init(apr_pool_t *pool, server_rec *s) -{ - h2_c2_logio_add_bytes_in = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_in); - h2_c2_logio_add_bytes_out = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_out); - - return APR_SUCCESS; -} - static apr_status_t c2_run_pre_connection(conn_rec *c2, apr_socket_t *csd) { if (c2->keepalives == 0) { @@ -607,8 +598,8 @@ static apr_status_t c2_process(h2_conn_ctx_t *conn_ctx, conn_rec *c) /* Add the raw bytes of the request (e.g. header frame lengths to * the logio for this request. */ - if (req->raw_bytes && h2_c2_logio_add_bytes_in) { - h2_c2_logio_add_bytes_in(c, req->raw_bytes); + if (req->raw_bytes && h2_c_logio_add_bytes_in) { + h2_c_logio_add_bytes_in(c, req->raw_bytes); } ap_process_request(r); @@ -710,9 +701,6 @@ static int h2_c2_hook_fixups(request_rec *r) return DECLINED; } -APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_c2_logio_add_bytes_in; -APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_c2_logio_add_bytes_out; - void h2_c2_register_hooks(void) { /* When the connection processing actually starts, we might diff --git a/modules/http2/h2_c2.h b/modules/http2/h2_c2.h index 0dd78a55973..58964a2ac43 100644 --- a/modules/http2/h2_c2.h +++ b/modules/http2/h2_c2.h @@ -50,12 +50,5 @@ void h2_c2_destroy(conn_rec *c2); apr_status_t h2_c2_process(conn_rec *c, apr_thread_t *thread, int worker_id); void h2_c2_register_hooks(void); -/* - * One time, post config initialization. - */ -apr_status_t h2_c2_init(apr_pool_t *pool, server_rec *s); - -extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_c2_logio_add_bytes_in; -extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_c2_logio_add_bytes_out; #endif /* defined(__mod_h2__h2_c2__) */ diff --git a/modules/http2/h2_c2_filter.c b/modules/http2/h2_c2_filter.c index 9df138161fc..96e56cdd6f9 100644 --- a/modules/http2/h2_c2_filter.c +++ b/modules/http2/h2_c2_filter.c @@ -32,6 +32,7 @@ #include "h2_private.h" #include "h2_conn_ctx.h" #include "h2_headers.h" +#include "h2_c1.h" #include "h2_c2_filter.h" #include "h2_c2.h" #include "h2_mplx.h" @@ -846,8 +847,8 @@ apr_status_t h2_c2_filter_request_in(ap_filter_t* f, apr_bucket_destroy(b); ap_remove_input_filter(f); - if (headers->raw_bytes && h2_c2_logio_add_bytes_in) { - h2_c2_logio_add_bytes_in(f->c, headers->raw_bytes); + if (headers->raw_bytes && h2_c_logio_add_bytes_in) { + h2_c_logio_add_bytes_in(f->c, headers->raw_bytes); } break; } diff --git a/modules/http2/h2_mplx.c b/modules/http2/h2_mplx.c index 09396166c71..c083f13c129 100644 --- a/modules/http2/h2_mplx.c +++ b/modules/http2/h2_mplx.c @@ -265,6 +265,8 @@ h2_mplx *h2_mplx_c1_create(h2_stream *stream0, server_rec *s, apr_pool_t *parent conn_ctx = h2_conn_ctx_get(m->c1); mplx_pollset_add(m, conn_ctx); + m->scratch_r = apr_pcalloc(m->pool, sizeof(*m->scratch_r)); + return m; failure: @@ -457,6 +459,17 @@ const h2_stream *h2_mplx_c2_stream_get(h2_mplx *m, int stream_id) return s; } + +static void c1_update_scoreboard(h2_mplx *m, h2_stream *stream) +{ + if (stream->c2) { + m->scratch_r->connection = stream->c2; + m->scratch_r->bytes_sent = stream->out_frame_octets; + ap_increment_counts(m->c1->sbh, m->scratch_r); + m->scratch_r->connection = NULL; + } +} + static void c1_purge_streams(h2_mplx *m) { h2_stream *stream; @@ -465,6 +478,9 @@ static void c1_purge_streams(h2_mplx *m) for (i = 0; i < m->spurge->nelts; ++i) { stream = APR_ARRAY_IDX(m->spurge, i, h2_stream*); ap_assert(stream->state == H2_SS_CLEANUP); + + c1_update_scoreboard(m, stream); + if (stream->input) { h2_beam_destroy(stream->input, m->c1); stream->input = NULL; @@ -482,6 +498,7 @@ static void c1_purge_streams(h2_mplx *m) "h2_mplx(%ld-%d): pollset_remove %d on purge", m->id, stream->id, c2_ctx->stream_id); } + h2_conn_ctx_destroy(c2); h2_c2_destroy(c2); } @@ -883,6 +900,9 @@ static void s_c2_done(h2_mplx *m, conn_rec *c2, h2_conn_ctx_t *conn_ctx) conn_ctx->done = 1; conn_ctx->done_at = apr_time_now(); ++c2->keepalives; + /* From here on, the final handling of c2 is done by c1 processing. + * Which means we can give it c1's scoreboard handle for updates. */ + c2->sbh = m->c1->sbh; ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c2, "h2_mplx(%s-%d): request done, %f ms elapsed", diff --git a/modules/http2/h2_mplx.h b/modules/http2/h2_mplx.h index cb0a85665e5..d5c4f9916f7 100644 --- a/modules/http2/h2_mplx.h +++ b/modules/http2/h2_mplx.h @@ -89,6 +89,8 @@ struct h2_mplx { struct h2_iqueue *streams_output_written; /* streams whose output has been written to */ #endif struct h2_workers *workers; /* h2 workers process wide instance */ + + request_rec *scratch_r; /* pseudo request_rec for scoreboard reporting */ }; apr_status_t h2_mplx_c1_child_init(apr_pool_t *pool, server_rec *s); diff --git a/modules/http2/h2_session.c b/modules/http2/h2_session.c index 812ad91a22d..dc00eee0ea8 100644 --- a/modules/http2/h2_session.c +++ b/modules/http2/h2_session.c @@ -406,8 +406,8 @@ static int on_frame_recv_cb(nghttp2_session *ng2s, /* A stream reset on a request it sent us. Could happen in a browser * when the user navigates away or cancels loading - maybe. */ h2_mplx_c1_client_rst(session->mplx, frame->hd.stream_id); - ++session->streams_reset; } + ++session->streams_reset; break; case NGHTTP2_GOAWAY: if (frame->goaway.error_code == 0 @@ -685,6 +685,33 @@ static apr_status_t init_callbacks(conn_rec *c, nghttp2_session_callbacks **pcb) return APR_SUCCESS; } +static void update_child_status(h2_session *session, int status, + const char *msg, const h2_stream *stream) +{ + /* Assume that we also change code/msg when something really happened and + * avoid updating the scoreboard in between */ + if (session->last_status_code != status + || session->last_status_msg != msg) { + char sbuffer[1024]; + sbuffer[0] = '\0'; + if (stream) { + apr_snprintf(sbuffer, sizeof(sbuffer), + ": stream %d, %s %s", + stream->id, + stream->request? stream->request->method : "", + stream->request? stream->request->path : ""); + } + apr_snprintf(session->status, sizeof(session->status), + "[%d/%d] %s%s", + (int)(session->remote.emitted_count + session->pushes_submitted), + (int)session->streams_done, + msg? msg : "-", sbuffer); + ap_update_child_status_from_server(session->c1->sbh, status, + session->c1, session->s); + ap_update_child_status_descr(session->c1->sbh, status, session->status); + } +} + static apr_status_t h2_session_shutdown_notice(h2_session *session) { apr_status_t status; @@ -714,10 +741,13 @@ static apr_status_t h2_session_shutdown(h2_session *session, int error, if (session->local.shutdown) { return APR_SUCCESS; } - if (!msg && error) { - msg = nghttp2_strerror(error); + + if (error && !msg) { + if (APR_STATUS_IS_EPIPE(error)) { + msg = "remote close"; + } } - + if (error || force_close) { /* not a graceful shutdown, we want to leave... * Do not start further streams that are waiting to be scheduled. @@ -728,6 +758,7 @@ static apr_status_t h2_session_shutdown(h2_session *session, int error, * we send. */ session->local.accepted_max = h2_mplx_c1_shutdown(session->mplx); session->local.error = error; + session->local.error_msg = msg; } else { /* graceful shutdown. we will continue processing all streams @@ -866,7 +897,7 @@ apr_status_t h2_session_create(h2_session **psession, conn_rec *c, request_rec * return APR_ENOTIMPL; } - h2_c1_io_init(&session->io, c, s); + h2_c1_io_init(&session->io, session); session->padding_max = h2_config_sgeti(s, H2_CONF_PADDING_BITS); if (session->padding_max) { session->padding_max = (0x01 << session->padding_max) - 1; @@ -1203,7 +1234,6 @@ static apr_status_t h2_session_send(h2_session *session) int ngrv; apr_status_t rv = APR_SUCCESS; - ap_update_child_status(session->c1->sbh, SERVER_BUSY_WRITE, NULL); while (nghttp2_session_want_write(session->ngh2)) { ngrv = nghttp2_session_send(session->ngh2); ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, session->c1, @@ -1221,8 +1251,7 @@ static apr_status_t h2_session_send(h2_session *session) } cleanup: if (rv != APR_SUCCESS) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, - H2_ERR_INTERNAL_ERROR, "c1 out writing"); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, rv, NULL); } return rv; } @@ -1251,8 +1280,10 @@ static apr_status_t on_stream_input(void *ctx, h2_stream *stream) H2_STRM_LOG(APLOGNO(10026), stream, "remote close missing")); nghttp2_submit_rst_stream(stream->session->ngh2, NGHTTP2_FLAG_NONE, stream->id, NGHTTP2_NO_ERROR); + update_child_status(session, SERVER_BUSY_WRITE, "reset", stream); goto cleanup; } + update_child_status(session, SERVER_BUSY_READ, "read", stream); h2_beam_report_consumption(stream->input); if (stream->state == H2_SS_CLOSED_R) { /* TODO: remove this stream from input polling */ @@ -1278,6 +1309,7 @@ static apr_status_t on_stream_output(void *ctx, h2_stream *stream) /* we dont poll output of stream 0, this should not be called */ return APR_SUCCESS; } + update_child_status(session, SERVER_BUSY_WRITE, "write", stream); return h2_stream_read_output(stream); } @@ -1299,32 +1331,13 @@ const char *h2_session_state_str(h2_session_state state) return StateNames[state]; } -static void update_child_status(h2_session *session, int status, const char *msg) -{ - /* Assume that we also change code/msg when something really happened and - * avoid updating the scoreboard in between */ - if (session->last_status_code != status - || session->last_status_msg != msg) { - apr_snprintf(session->status, sizeof(session->status), - "%s, streams: %d/%d/%d/%d/%d (open/recv/resp/push/rst)", - msg? msg : "-", - (int)session->open_streams, - (int)session->remote.emitted_count, - (int)session->responses_submitted, - (int)session->pushes_submitted, - (int)session->pushes_reset + session->streams_reset); - ap_update_child_status_descr(session->c1->sbh, status, session->status); - } -} - static void transit(h2_session *session, const char *action, h2_session_state nstate) { int ostate; if (session->state != nstate) { ostate = session->state; - session->state = nstate; - + ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c1, H2_SSSN_LOG(APLOGNO(03078), session, "transit [%s] -- %s --> [%s]"), @@ -1340,22 +1353,21 @@ static void transit(h2_session *session, const char *action, h2_session_state ns * If we return to mpm right away, this connection has the * same chance of being cleaned up by the mpm as connections * that already served requests - not fair. */ - update_child_status(session, SERVER_BUSY_READ, "idle"); ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, session->c1, H2_SSSN_LOG("", session, "enter idle")); } else { /* normal keepalive setup */ - update_child_status(session, SERVER_BUSY_KEEPALIVE, "keepalive"); ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, session->c1, H2_SSSN_LOG("", session, "enter keepalive")); } + session->state = nstate; break; case H2_SESSION_ST_DONE: - update_child_status(session, SERVER_CLOSING, "done"); break; default: /* nop */ + session->state = nstate; break; } } @@ -1412,9 +1424,6 @@ static void h2_session_ev_input_exhausted(h2_session *session, int arg, const ch static void h2_session_ev_local_goaway(h2_session *session, int arg, const char *msg) { cleanup_unprocessed_streams(session); - if (!session->remote.shutdown) { - update_child_status(session, SERVER_CLOSING, "local goaway"); - } transit(session, "local goaway", H2_SESSION_ST_DONE); } @@ -1425,7 +1434,6 @@ static void h2_session_ev_remote_goaway(h2_session *session, int arg, const char session->remote.accepting = 0; session->remote.shutdown = 1; cleanup_unprocessed_streams(session); - update_child_status(session, SERVER_CLOSING, "remote goaway"); transit(session, "remote goaway", H2_SESSION_ST_DONE); } } @@ -1550,6 +1558,7 @@ static void ev_stream_open(h2_session *session, h2_stream *stream) /* Stream state OPEN means we have received all request headers * and can start processing the stream. */ h2_iq_append(session->ready_to_process, stream->id); + update_child_status(session, SERVER_BUSY_READ, "schedule", stream); } static void ev_stream_closed(h2_session *session, h2_stream *stream) @@ -1609,6 +1618,8 @@ static void on_stream_state_enter(void *ctx, h2_stream *stream) case H2_SS_CLEANUP: nghttp2_session_set_stream_user_data(session->ngh2, stream->id, NULL); h2_mplx_c1_stream_cleanup(session->mplx, stream, &session->open_streams); + ++session->streams_done; + update_child_status(session, SERVER_BUSY_WRITE, "done", stream); if (session->open_streams == 0) { h2_session_dispatch_event(session, H2_SESSION_EV_NO_MORE_STREAMS, 0, "stream done"); @@ -1653,7 +1664,7 @@ static void on_stream_state_event(void *ctx, h2_stream *stream, } void h2_session_dispatch_event(h2_session *session, h2_session_event_t ev, - int arg, const char *msg) + apr_status_t arg, const char *msg) { switch (ev) { case H2_SESSION_EV_INIT: @@ -1719,15 +1730,13 @@ apr_status_t h2_session_process(h2_session *session, int async) } if (H2_SESSION_ST_INIT == session->state) { - ap_update_child_status_from_conn(c->sbh, SERVER_BUSY_READ, c); if (!h2_protocol_is_acceptable_c1(c, session->r, 1)) { - update_child_status(session, SERVER_BUSY_READ, - "inadequate security"); - h2_session_shutdown(session, - NGHTTP2_INADEQUATE_SECURITY, NULL, 1); + const char *msg = nghttp2_strerror(NGHTTP2_INADEQUATE_SECURITY); + update_child_status(session, SERVER_BUSY_READ, msg, NULL); + h2_session_shutdown(session, APR_EINVAL, msg, 1); } else { - update_child_status(session, SERVER_BUSY_READ, "init"); + update_child_status(session, SERVER_BUSY_READ, "init", NULL); status = h2_session_start(session, &rv); ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c, H2_SSSN_LOG(APLOGNO(03079), session, @@ -1736,7 +1745,7 @@ apr_status_t h2_session_process(h2_session *session, int async) c->local_addr->port); if (status != APR_SUCCESS) { h2_session_dispatch_event(session, - H2_SESSION_EV_CONN_ERROR, 0, NULL); + H2_SESSION_EV_CONN_ERROR, status, NULL); } else { h2_session_dispatch_event(session, H2_SESSION_EV_INIT, 0, NULL); @@ -1790,7 +1799,7 @@ apr_status_t h2_session_process(h2_session *session, int async) status = h2_c1_io_assure_flushed(&session->io); if (APR_SUCCESS != status) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, status, NULL); } switch (session->state) { @@ -1826,7 +1835,7 @@ apr_status_t h2_session_process(h2_session *session, int async) status = h2_mplx_c1_poll(session->mplx, 0, on_stream_input, on_stream_output, session); if (APR_SUCCESS != status && !APR_STATUS_IS_TIMEUP(status)) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, status, NULL); break; } h2_c1_read(session); @@ -1835,7 +1844,7 @@ apr_status_t h2_session_process(h2_session *session, int async) case H2_SESSION_ST_WAIT: status = h2_c1_io_assure_flushed(&session->io); if (APR_SUCCESS != status) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, status, NULL); break; } /* No IO happening and input is exhausted. Make sure we have @@ -1844,11 +1853,11 @@ apr_status_t h2_session_process(h2_session *session, int async) status = h2_mplx_c1_poll(session->mplx, session->s->timeout, on_stream_input, on_stream_output, session); if (APR_STATUS_IS_TIMEUP(status)) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, 0, "timeout"); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, status, NULL); break; } else if (APR_SUCCESS != status) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, "error"); + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, status, NULL); break; } break; @@ -1861,7 +1870,7 @@ apr_status_t h2_session_process(h2_session *session, int async) ap_log_cerror(APLOG_MARK, APLOG_ERR, APR_EGENERAL, c, H2_SSSN_LOG(APLOGNO(03080), session, "unknown state")); - h2_session_dispatch_event(session, H2_SESSION_EV_PROTO_ERROR, 0, NULL); + h2_session_dispatch_event(session, H2_SESSION_EV_PROTO_ERROR, APR_EGENERAL, NULL); break; } } @@ -1872,11 +1881,27 @@ leaving: H2_SSSN_MSG(session, "process returns")); } - if ((session->state != H2_SESSION_ST_DONE) - && (APR_STATUS_IS_EOF(status) + if (session->state == H2_SESSION_ST_DONE) { + if (session->local.error) { + char buffer[128]; + const char *msg; + if (session->local.error_msg) { + msg = session->local.error_msg; + } + else { + msg = apr_strerror(session->local.error, buffer, sizeof(buffer)); + } + update_child_status(session, SERVER_CLOSING, msg, NULL); + } + else { + update_child_status(session, SERVER_CLOSING, "done", NULL); + } + } + else if (APR_STATUS_IS_EOF(status) || APR_STATUS_IS_ECONNRESET(status) - || APR_STATUS_IS_ECONNABORTED(status))) { - h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); + || APR_STATUS_IS_ECONNABORTED(status)) { + h2_session_dispatch_event(session, H2_SESSION_EV_CONN_ERROR, status, NULL); + update_child_status(session, SERVER_CLOSING, "error", NULL); } return (session->state == H2_SESSION_ST_DONE)? APR_EOF : APR_SUCCESS; diff --git a/modules/http2/h2_session.h b/modules/http2/h2_session.h index 4680b3c869e..76c8ef6b87d 100644 --- a/modules/http2/h2_session.h +++ b/modules/http2/h2_session.h @@ -91,6 +91,7 @@ typedef struct h2_session { struct h2_stream_monitor *monitor;/* monitor callbacks for streams */ int open_streams; /* number of streams processing */ + int streams_done; /* number of http/2 streams handled */ int responses_submitted; /* number of http/2 responses submitted */ int streams_reset; /* number of http/2 streams reset by client */ int pushes_promised; /* number of http/2 push promises submitted */ diff --git a/modules/http2/h2_version.h b/modules/http2/h2_version.h index ec1225d4d04..847c9d9ff75 100644 --- a/modules/http2/h2_version.h +++ b/modules/http2/h2_version.h @@ -27,7 +27,7 @@ * @macro * Version number of the http2 module as c string */ -#define MOD_HTTP2_VERSION "2.0.0" +#define MOD_HTTP2_VERSION "2.0.1" /** * @macro @@ -35,7 +35,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 0x020000 +#define MOD_HTTP2_VERSION_NUM 0x020001 #endif /* mod_h2_h2_version_h */ diff --git a/modules/http2/mod_http2.c b/modules/http2/mod_http2.c index 70c5ed27844..1784b04f168 100644 --- a/modules/http2/mod_http2.c +++ b/modules/http2/mod_http2.c @@ -161,10 +161,7 @@ static int h2_post_config(apr_pool_t *p, apr_pool_t *plog, if (status == APR_SUCCESS) { status = h2_switch_init(p, s); } - if (status == APR_SUCCESS) { - status = h2_c2_init(p, s); - } - + return status; }