diff --git a/ChangeLog b/ChangeLog index c90625e7..dbbd845a 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,14 @@ +v1.5.5 +-------------------------------------------------------------------------------- + * Fix async write issue that sometimes led to selection of wrong timeout + vs. keepalive timeout selection for idle sessions. + * Checking LimitRequestLine, LimitRequestFields and + LimitRequestFieldSize configurated values for incoming streams. Returning + HTTP status 431 for too long/many headers fields and 414 for a too long + pseudo header. + * Tracking conn_rec->current_thread on slave connections, so + that mod_lua finds the correct one. Fixes PR 59542. + v1.5.3 -------------------------------------------------------------------------------- * slave connections have conn_rec->aborted flag set when a stream diff --git a/configure.ac b/configure.ac index e8a3f811..9f464a8f 100644 --- a/configure.ac +++ b/configure.ac @@ -14,7 +14,7 @@ # AC_PREREQ([2.69]) -AC_INIT([mod_http2], [1.5.3], [stefan.eissing@greenbytes.de]) +AC_INIT([mod_http2], [1.5.5], [stefan.eissing@greenbytes.de]) LT_PREREQ([2.2.6]) LT_INIT() diff --git a/mod_http2/h2_from_h1.c b/mod_http2/h2_from_h1.c index eb866a79..0f893ec1 100644 --- a/mod_http2/h2_from_h1.c +++ b/mod_http2/h2_from_h1.c @@ -291,7 +291,8 @@ static void fix_vary(request_rec *r) } } -static void set_basic_http_header(request_rec *r, apr_table_t *headers) +void h2_from_h1_set_basic_http_header(apr_table_t *headers, request_rec *r, + apr_pool_t *pool) { char *date = NULL; const char *proxy_date = NULL; @@ -302,7 +303,7 @@ static void set_basic_http_header(request_rec *r, apr_table_t *headers) * keep the set-by-proxy server and date headers, otherwise * generate a new server header / date header */ - if (r->proxyreq != PROXYREQ_NONE) { + if (r && r->proxyreq != PROXYREQ_NONE) { proxy_date = apr_table_get(r->headers_out, "Date"); if (!proxy_date) { /* @@ -310,25 +311,29 @@ static void set_basic_http_header(request_rec *r, apr_table_t *headers) * our own Date header and pass it over to proxy_date later to * avoid a compiler warning. */ - date = apr_palloc(r->pool, APR_RFC822_DATE_LEN); + date = apr_palloc(pool, APR_RFC822_DATE_LEN); ap_recent_rfc822_date(date, r->request_time); } server = apr_table_get(r->headers_out, "Server"); } else { - date = apr_palloc(r->pool, APR_RFC822_DATE_LEN); - ap_recent_rfc822_date(date, r->request_time); + date = apr_palloc(pool, APR_RFC822_DATE_LEN); + ap_recent_rfc822_date(date, r? r->request_time : apr_time_now()); } apr_table_setn(headers, "Date", proxy_date ? proxy_date : date ); - apr_table_unset(r->headers_out, "Date"); + if (r) { + apr_table_unset(r->headers_out, "Date"); + } if (!server && *us) { server = us; } if (server) { apr_table_setn(headers, "Server", server); - apr_table_unset(r->headers_out, "Server"); + if (r) { + apr_table_unset(r->headers_out, "Server"); + } } } @@ -445,7 +450,7 @@ static h2_response *create_response(h2_from_h1 *from_h1, request_rec *r) headers = apr_table_make(r->pool, 10); - set_basic_http_header(r, headers); + h2_from_h1_set_basic_http_header(headers, r, r->pool); if (r->status == HTTP_NOT_MODIFIED) { apr_table_do((int (*)(void *, const char *, const char *)) copy_header, (void *) headers, r->headers_out, diff --git a/mod_http2/h2_from_h1.h b/mod_http2/h2_from_h1.h index af5dea24..71cc35fa 100644 --- a/mod_http2/h2_from_h1.h +++ b/mod_http2/h2_from_h1.h @@ -69,4 +69,7 @@ apr_status_t h2_response_output_filter(ap_filter_t *f, apr_bucket_brigade *bb); apr_status_t h2_response_trailers_filter(ap_filter_t *f, apr_bucket_brigade *bb); +void h2_from_h1_set_basic_http_header(apr_table_t *headers, request_rec *r, + apr_pool_t *pool); + #endif /* defined(__mod_h2__h2_from_h1__) */ diff --git a/mod_http2/h2_h2.c b/mod_http2/h2_h2.c index 5329f317..825cd77e 100644 --- a/mod_http2/h2_h2.c +++ b/mod_http2/h2_h2.c @@ -485,9 +485,9 @@ int h2_is_acceptable_connection(conn_rec *c, int require_all) if (strncmp("TLS", val, 3) || !strcmp("TLSv1", val) || !strcmp("TLSv1.1", val)) { - ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, c, APLOGNO(03050) - "h2_h2(%ld): tls protocol not suitable: %s", - (long)c->id, val); + ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, c, APLOGNO(03050) + "h2_h2(%ld): tls protocol not suitable: %s", + (long)c->id, val); return 0; } } diff --git a/mod_http2/h2_mplx.c b/mod_http2/h2_mplx.c index 3ae02f4f..a88b0718 100644 --- a/mod_http2/h2_mplx.c +++ b/mod_http2/h2_mplx.c @@ -282,11 +282,11 @@ h2_mplx *h2_mplx_create(conn_rec *c, apr_pool_t *parent, m->stream_max_mem = h2_config_geti(conf, H2_CONF_STREAM_MAX_MEM); m->streams = h2_ihash_create(m->pool, offsetof(h2_stream,id)); + m->sready = h2_ihash_create(m->pool, offsetof(h2_stream,id)); m->shold = h2_ihash_create(m->pool, offsetof(h2_stream,id)); m->spurge = h2_ihash_create(m->pool, offsetof(h2_stream,id)); m->q = h2_iq_create(m->pool, m->max_streams); m->tasks = h2_ihash_create(m->pool, offsetof(h2_task,stream_id)); - m->ready_tasks = h2_ihash_create(m->pool, offsetof(h2_task,stream_id)); m->stream_timeout = stream_timeout; m->workers = workers; @@ -373,7 +373,6 @@ static void task_destroy(h2_mplx *m, h2_task *task, int called_from_master) && !task->rst_error); h2_ihash_remove(m->tasks, task->stream_id); - h2_ihash_remove(m->ready_tasks, task->stream_id); if (m->redo_tasks) { h2_ihash_remove(m->redo_tasks, task->stream_id); } @@ -428,7 +427,7 @@ static void stream_done(h2_mplx *m, h2_stream *stream, int rst_error) * stream destruction until the task is done. */ h2_iq_remove(m->q, stream->id); - h2_ihash_remove(m->ready_tasks, stream->id); + h2_ihash_remove(m->sready, stream->id); h2_ihash_remove(m->streams, stream->id); if (stream->input) { m->tx_handles_reserved += h2_beam_get_files_beamed(stream->input); @@ -465,8 +464,10 @@ static int task_print(void *ctx, void *val) { h2_mplx *m = ctx; h2_task *task = val; - h2_stream *stream = h2_ihash_get(m->streams, task->stream_id); - if (task->request) { + + if (task && task->request) { + h2_stream *stream = h2_ihash_get(m->streams, task->stream_id); + ap_log_cerror(APLOG_MARK, APLOG_WARNING, 0, m->c, /* NO APLOGNO */ "->03198: h2_stream(%s): %s %s %s -> %s %d" "[orph=%d/started=%d/done=%d]", @@ -488,6 +489,15 @@ static int task_print(void *ctx, void *val) return 1; } +static int task_abort_connection(void *ctx, void *val) +{ + h2_task *task = val; + if (task->c) { + task->c->aborted = 1; + } + return 1; +} + apr_status_t h2_mplx_release_and_join(h2_mplx *m, apr_thread_cond_t *wait) { apr_status_t status; @@ -537,6 +547,8 @@ apr_status_t h2_mplx_release_and_join(h2_mplx *m, apr_thread_cond_t *wait) * and workers *should* return in a timely fashion. */ for (i = 0; m->workers_busy > 0; ++i) { + h2_ihash_iter(m->tasks, task_abort_connection, m); + m->join_wait = wait; status = apr_thread_cond_timedwait(wait, m->lock, apr_time_from_sec(wait_secs)); @@ -644,11 +656,10 @@ apr_status_t h2_mplx_in_update_windows(h2_mplx *m) return status; } -static int task_iter_first(void *ctx, void *val) +static int stream_iter_first(void *ctx, void *val) { - task_iter_ctx *tctx = ctx; - h2_task *task = val; - tctx->task = task; + h2_stream **pstream = ctx; + *pstream = val; return 0; } @@ -660,17 +671,11 @@ h2_stream *h2_mplx_next_submit(h2_mplx *m) AP_DEBUG_ASSERT(m); if ((status = enter_mutex(m, &acquired)) == APR_SUCCESS) { - task_iter_ctx ctx; - ctx.m = m; - ctx.task = NULL; - h2_ihash_iter(m->ready_tasks, task_iter_first, &ctx); - - if (ctx.task && !m->aborted) { - h2_task *task = ctx.task; - - h2_ihash_remove(m->ready_tasks, task->stream_id); - stream = h2_ihash_get(m->streams, task->stream_id); - if (stream && task) { + h2_ihash_iter(m->sready, stream_iter_first, &stream); + if (stream) { + h2_task *task = h2_ihash_get(m->tasks, stream->id); + h2_ihash_remove(m->sready, stream->id); + if (task) { task->submitted = 1; if (task->rst_error) { h2_stream_rst(stream, task->rst_error); @@ -681,24 +686,11 @@ h2_stream *h2_mplx_next_submit(h2_mplx *m) task->output.beam); } } - else if (task) { - /* We have the io ready, but the stream has gone away, maybe - * reset by the client. Should no longer happen since such - * streams should clear io's from the ready queue. - */ - ap_log_cerror(APLOG_MARK, APLOG_WARNING, 0, m->c, APLOGNO(03347) - "h2_mplx(%s): stream for response closed, " - "resetting io to close request processing", - task->id); - h2_task_rst(task, H2_ERR_STREAM_CLOSED); - if (!task->worker_started || task->worker_done) { - task_destroy(m, task, 1); - } - else { - /* hang around until the h2_task is done, but - * shutdown output */ - h2_task_shutdown(task, 0); - } + else { + /* We have the stream ready without a task. This happens + * when we fail streams early. A response should already + * be present. */ + AP_DEBUG_ASSERT(stream->response || stream->rst_error); } } leave_mutex(m, acquired); @@ -731,7 +723,7 @@ static apr_status_t out_open(h2_mplx *m, int stream_id, h2_response *response) h2_beam_mutex_set(task->output.beam, beam_enter, task->cond, m); } - h2_ihash_add(m->ready_tasks, task); + h2_ihash_add(m->sready, stream); if (response && response->http_status < 300) { /* we might see some file buckets in the output, see * if we have enough handles reserved. */ @@ -762,18 +754,22 @@ apr_status_t h2_mplx_out_open(h2_mplx *m, int stream_id, h2_response *response) static apr_status_t out_close(h2_mplx *m, h2_task *task) { apr_status_t status = APR_SUCCESS; - h2_stream *stream = h2_ihash_get(m->streams, task->stream_id); + h2_stream *stream; - if (!task || !stream) { + if (!task) { return APR_ECONNABORTED; } - + + stream = h2_ihash_get(m->streams, task->stream_id); + if (!stream) { + return APR_ECONNABORTED; + } + if (!task->response && !task->rst_error) { /* In case a close comes before a response was created, - * insert an error one so that our streams can properly - * reset. + * insert an error one so that our streams can properly reset. */ - h2_response *r = h2_response_die(task->stream_id, APR_EGENERAL, + h2_response *r = h2_response_die(task->stream_id, 500, task->request, m->pool); status = out_open(m, task->stream_id, r); ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, m->c, @@ -858,6 +854,10 @@ apr_status_t h2_mplx_process(h2_mplx *m, struct h2_stream *stream, if (m->aborted) { status = APR_ECONNABORTED; } + else if (stream->response) { + /* already have a respone, schedule for submit */ + h2_ihash_add(m->sready, stream); + } else { h2_beam_create(&stream->input, stream->pool, stream->id, "input", 0); diff --git a/mod_http2/h2_mplx.h b/mod_http2/h2_mplx.h index 9b316b0b..17cc75f1 100644 --- a/mod_http2/h2_mplx.h +++ b/mod_http2/h2_mplx.h @@ -73,12 +73,12 @@ struct h2_mplx { unsigned int need_registration : 1; struct h2_ihash_t *streams; /* all streams currently processing */ + struct h2_ihash_t *sready; /* all streams ready for response */ struct h2_ihash_t *shold; /* all streams done with task ongoing */ struct h2_ihash_t *spurge; /* all streams done, ready for destroy */ struct h2_iqueue *q; /* all stream ids that need to be started */ struct h2_ihash_t *tasks; /* all tasks started and not destroyed */ - struct h2_ihash_t *ready_tasks; /* all tasks ready for submit */ struct h2_ihash_t *redo_tasks; /* all tasks that need to be redone */ apr_uint32_t max_streams; /* max # of concurrent streams */ diff --git a/mod_http2/h2_ngn_shed.c b/mod_http2/h2_ngn_shed.c index ed3459f0..805c7d97 100644 --- a/mod_http2/h2_ngn_shed.c +++ b/mod_http2/h2_ngn_shed.c @@ -274,6 +274,12 @@ apr_status_t h2_ngn_shed_pull_task(h2_ngn_shed *shed, ngn->no_live++; *ptask = entry->task; entry->task->assigned = ngn; + /* task will now run in ngn's own thread. Modules like lua + * seem to require the correct thread set in the conn_rec. + * See PR 59542. */ + if (entry->task->c && ngn->c) { + entry->task->c->current_thread = ngn->c->current_thread; + } return APR_SUCCESS; } diff --git a/mod_http2/h2_proxy_session.c b/mod_http2/h2_proxy_session.c index a2a5631f..34b58490 100644 --- a/mod_http2/h2_proxy_session.c +++ b/mod_http2/h2_proxy_session.c @@ -336,10 +336,10 @@ static int on_data_chunk_recv(nghttp2_session *ngh2, uint8_t flags, stream = nghttp2_session_get_stream_user_data(ngh2, stream_id); if (!stream) { - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, stream->r, APLOGNO(03358) - "h2_proxy_session(%s): recv data chunk for " - "unknown stream %d, ignored", - session->id, stream_id); + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO(03358) + "h2_proxy_session(%s): recv data chunk for " + "unknown stream %d, ignored", + session->id, stream_id); return 0; } @@ -422,9 +422,9 @@ static ssize_t stream_data_read(nghttp2_session *ngh2, int32_t stream_id, *data_flags = 0; stream = nghttp2_session_get_stream_user_data(ngh2, stream_id); if (!stream) { - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, stream->r, APLOGNO(03361) - "h2_proxy_stream(%s): data_read, stream %d not found", - stream->session->id, stream_id); + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO(03361) + "h2_proxy_stream(%s): data_read, stream %d not found", + stream->session->id, stream_id); return NGHTTP2_ERR_CALLBACK_FAILURE; } @@ -581,6 +581,7 @@ static apr_status_t open_stream(h2_proxy_session *session, const char *url, h2_proxy_stream *stream; apr_uri_t puri; const char *authority, *scheme, *path; + apr_status_t status; stream = apr_pcalloc(r->pool, sizeof(*stream)); @@ -595,7 +596,10 @@ static apr_status_t open_stream(h2_proxy_session *session, const char *url, stream->req = h2_req_create(1, stream->pool, 0); - apr_uri_parse(stream->pool, url, &puri); + status = apr_uri_parse(stream->pool, url, &puri); + if (status != APR_SUCCESS) + return status; + scheme = (strcmp(puri.scheme, "h2")? "http" : "https"); authority = puri.hostname; if (!ap_strchr_c(authority, ':') && puri.port @@ -763,7 +767,7 @@ apr_status_t h2_proxy_session_submit(h2_proxy_session *session, apr_status_t status; status = open_stream(session, url, r, &stream); - if (status == OK) { + if (status == APR_SUCCESS) { ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(03381) "process stream(%d): %s %s%s, original: %s", stream->id, stream->req->method, diff --git a/mod_http2/h2_response.c b/mod_http2/h2_response.c index eb9043d0..4cafd355 100644 --- a/mod_http2/h2_response.c +++ b/mod_http2/h2_response.c @@ -171,13 +171,14 @@ h2_response *h2_response_die(int stream_id, apr_status_t type, { apr_table_t *headers = apr_table_make(pool, 5); char *date = NULL; + int status = (type >= 200 && type < 600)? type : 500; date = apr_palloc(pool, APR_RFC822_DATE_LEN); ap_recent_rfc822_date(date, req->request_time); apr_table_setn(headers, "Date", date); apr_table_setn(headers, "Server", ap_get_server_banner()); - return h2_response_create_int(stream_id, 0, 500, headers, NULL, pool); + return h2_response_create_int(stream_id, 0, status, headers, NULL, pool); } h2_response *h2_response_clone(apr_pool_t *pool, h2_response *from) diff --git a/mod_http2/h2_session.c b/mod_http2/h2_session.c index 5ee45acf..cdee085f 100644 --- a/mod_http2/h2_session.c +++ b/mod_http2/h2_session.c @@ -57,7 +57,7 @@ static int h2_session_status_from_apr_status(apr_status_t rv) return NGHTTP2_ERR_WOULDBLOCK; } else if (APR_STATUS_IS_EOF(rv)) { - return NGHTTP2_ERR_EOF; + return NGHTTP2_ERR_EOF; } return NGHTTP2_ERR_PROTO; } @@ -133,7 +133,6 @@ h2_stream *h2_session_open_stream(h2_session *session, int stream_id, stream = h2_stream_open(stream_id, stream_pool, session, initiated_on, req); - ++session->open_streams; ++session->unanswered_streams; nghttp2_session_set_stream_user_data(session->ngh2, stream_id, stream); h2_ihash_add(session->streams, stream); @@ -151,6 +150,7 @@ h2_stream *h2_session_open_stream(h2_session *session, int stream_id, session->remote.emitted_max = stream->id; } } + dispatch_event(session, H2_SESSION_EV_STREAM_OPEN, 0, NULL); return stream; } @@ -252,7 +252,7 @@ static int on_invalid_frame_recv_cb(nghttp2_session *ngh2, h2_util_frame_print(frame, buffer, sizeof(buffer)/sizeof(buffer[0])); ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, APLOGNO(03063) - "h2_session(%ld): recv unknown FRAME[%s], frames=%ld/%ld (r/s)", + "h2_session(%ld): recv invalid FRAME[%s], frames=%ld/%ld (r/s)", session->id, buffer, (long)session->frames_received, (long)session->frames_sent); } @@ -386,7 +386,6 @@ static int on_header_cb(nghttp2_session *ngh2, const nghttp2_frame *frame, h2_stream * stream; apr_status_t status; - (void)ngh2; (void)flags; if (!is_accepting_streams(session)) { /* just ignore */ @@ -397,15 +396,14 @@ static int on_header_cb(nghttp2_session *ngh2, const nghttp2_frame *frame, if (!stream) { ap_log_cerror(APLOG_MARK, APLOG_ERR, 0, session->c, APLOGNO(02920) - "h2_session: stream(%ld-%d): on_header for unknown stream", + "h2_session: stream(%ld-%d): on_header unknown stream", session->id, (int)frame->hd.stream_id); return NGHTTP2_ERR_TEMPORAL_CALLBACK_FAILURE; } status = h2_stream_add_header(stream, (const char *)name, namelen, (const char *)value, valuelen); - - if (status != APR_SUCCESS) { + if (status != APR_SUCCESS && !stream->response) { return NGHTTP2_ERR_TEMPORAL_CALLBACK_FAILURE; } return 0; @@ -1294,6 +1292,7 @@ static apr_status_t submit_response(h2_session *session, h2_stream *stream) stream->id, err); } + stream->submitted = 1; --session->unanswered_streams; if (stream->request && stream->request->initiated_on) { ++session->pushes_submitted; @@ -1301,7 +1300,7 @@ static apr_status_t submit_response(h2_session *session, h2_stream *stream) else { ++session->responses_submitted; } - + if (nghttp2_is_fatal(rv)) { status = APR_EGENERAL; dispatch_event(session, H2_SESSION_EV_PROTO_ERROR, rv, nghttp2_strerror(rv)); @@ -1472,10 +1471,10 @@ apr_status_t h2_session_stream_done(h2_session *session, h2_stream *stream) "h2_stream(%ld-%d): EOS bucket cleanup -> done", session->id, stream->id); h2_ihash_remove(session->streams, stream->id); - --session->open_streams; --session->unanswered_streams; h2_mplx_stream_done(session->mplx, stream); + dispatch_event(session, H2_SESSION_EV_STREAM_DONE, 0, NULL); return APR_SUCCESS; } @@ -1861,6 +1860,9 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) * 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. */ + ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, session->c, + "h2_session(%ld): NO_IO event, %d streams open", + session->id, session->open_streams); if (!session->open_streams) { if (!is_accepting_streams(session)) { /* We are no longer accepting new streams and have @@ -1872,7 +1874,7 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) apr_time_t now = apr_time_now(); /* When we have no streams, no task event are possible, * switch to blocking reads */ - transit(session, "no io", H2_SESSION_ST_IDLE); + transit(session, "no io (keepalive)", H2_SESSION_ST_IDLE); session->idle_until = (session->remote.emitted_count? session->s->keep_alive_timeout : session->s->timeout) + now; @@ -1881,6 +1883,9 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) } else if (!has_unsubmitted_streams(session) && !has_suspended_streams(session)) { + transit(session, "no io (flow wait)", H2_SESSION_ST_IDLE); + session->idle_until = apr_time_now() + session->s->timeout; + session->keep_sync_until = session->idle_until; /* none of our streams is waiting for a response or * new output data from task processing, * switch to blocking reads. We are probably waiting on @@ -1889,9 +1894,6 @@ static void h2_session_ev_no_io(h2_session *session, int arg, const char *msg) dispatch_event(session, H2_SESSION_EV_CONN_ERROR, 0, NULL); return; } - transit(session, "no io", H2_SESSION_ST_IDLE); - session->idle_until = apr_time_now() + session->s->timeout; - session->keep_sync_until = session->idle_until; } else { /* Unable to do blocking reads, as we wait on events from @@ -1925,7 +1927,6 @@ static void h2_session_ev_data_read(h2_session *session, int arg, const char *ms case H2_SESSION_ST_WAIT: transit(session, "data read", H2_SESSION_ST_BUSY); break; - /* fall through */ default: /* nop */ break; @@ -1970,6 +1971,39 @@ static void h2_session_ev_pre_close(h2_session *session, int arg, const char *ms } } +static void h2_session_ev_stream_open(h2_session *session, int arg, const char *msg) +{ + ++session->open_streams; + switch (session->state) { + case H2_SESSION_ST_IDLE: + if (session->open_streams == 1) { + /* enter tiomeout, since we have a stream again */ + session->idle_until = (session->s->timeout + apr_time_now()); + } + break; + default: + break; + } +} + +static void h2_session_ev_stream_done(h2_session *session, int arg, const char *msg) +{ + --session->open_streams; + if (session->open_streams <= 0) { + } + switch (session->state) { + case H2_SESSION_ST_IDLE: + if (session->open_streams == 0) { + /* enter keepalive timeout, since we no longer have streams */ + session->idle_until = (session->s->keep_alive_timeout + + apr_time_now()); + } + break; + default: + break; + } +} + static void dispatch_event(h2_session *session, h2_session_event_t ev, int arg, const char *msg) { @@ -2010,6 +2044,12 @@ static void dispatch_event(h2_session *session, h2_session_event_t ev, case H2_SESSION_EV_PRE_CLOSE: h2_session_ev_pre_close(session, arg, msg); break; + case H2_SESSION_EV_STREAM_OPEN: + h2_session_ev_stream_open(session, arg, msg); + break; + case H2_SESSION_EV_STREAM_DONE: + h2_session_ev_stream_done(session, arg, msg); + break; default: ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, session->c, "h2_session(%ld): unknown event %d", @@ -2074,8 +2114,10 @@ apr_status_t h2_session_process(h2_session *session, int async) /* make certain, we send everything before we idle */ if (!session->keep_sync_until && async && !session->open_streams && !session->r && session->remote.emitted_count) { - ap_log_cerror( APLOG_MARK, APLOG_TRACE1, status, c, - "h2_session(%ld): async idle, nonblock read", session->id); + ap_log_cerror( APLOG_MARK, APLOG_TRACE3, status, c, + "h2_session(%ld): async idle, nonblock read, " + "%d streams open", session->id, + session->open_streams); /* We do not return to the async mpm immediately, since under * load, mpms show the tendency to throw keep_alive connections * away very rapidly. @@ -2108,6 +2150,10 @@ apr_status_t h2_session_process(h2_session *session, int async) } } else { + ap_log_cerror( APLOG_MARK, APLOG_TRACE3, status, c, + "h2_session(%ld): sync idle, stutter 1-sec, " + "%d streams open", session->id, + session->open_streams); /* We wait in smaller increments, using a 1 second timeout. * That gives us the chance to check for MPMQ_STOPPING often. */ @@ -2133,8 +2179,16 @@ apr_status_t h2_session_process(h2_session *session, int async) session->keep_sync_until = 0; } if (now > session->idle_until) { + ap_log_cerror( APLOG_MARK, APLOG_TRACE3, status, c, + "h2_session(%ld): keepalive timeout", + session->id); dispatch_event(session, H2_SESSION_EV_CONN_TIMEOUT, 0, "timeout"); } + else { + ap_log_cerror( APLOG_MARK, APLOG_TRACE3, status, c, + "h2_session(%ld): keepalive, %f sec left", + session->id, (session->idle_until - now) / 1000000.0f); + } /* continue reading handling */ } else { diff --git a/mod_http2/h2_session.h b/mod_http2/h2_session.h index 32202dc3..06142f5a 100644 --- a/mod_http2/h2_session.h +++ b/mod_http2/h2_session.h @@ -70,6 +70,8 @@ typedef enum { H2_SESSION_EV_NGH2_DONE, /* nghttp2 wants neither read nor write anything */ H2_SESSION_EV_MPM_STOPPING, /* the process is stopping */ H2_SESSION_EV_PRE_CLOSE, /* connection will close after this */ + H2_SESSION_EV_STREAM_OPEN, /* stream has been opened */ + H2_SESSION_EV_STREAM_DONE, /* stream has been handled completely */ } h2_session_event_t; typedef struct h2_session { diff --git a/mod_http2/h2_stream.c b/mod_http2/h2_stream.c index dcc25da4..dc29d706 100644 --- a/mod_http2/h2_stream.c +++ b/mod_http2/h2_stream.c @@ -290,6 +290,40 @@ apr_status_t h2_stream_add_header(h2_stream *stream, const char *value, size_t vlen) { AP_DEBUG_ASSERT(stream); + if (!stream->response) { + if (name[0] == ':') { + if ((vlen) > stream->session->s->limit_req_line) { + /* pseudo header: approximation of request line size check */ + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, stream->session->c, + "h2_stream(%ld-%d): pseudo header %s too long", + stream->session->id, stream->id, name); + return h2_stream_set_error(stream, + HTTP_REQUEST_URI_TOO_LARGE); + } + } + else if ((nlen + 2 + vlen) > stream->session->s->limit_req_fieldsize) { + /* header too long */ + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, stream->session->c, + "h2_stream(%ld-%d): header %s too long", + stream->session->id, stream->id, name); + return h2_stream_set_error(stream, + HTTP_REQUEST_HEADER_FIELDS_TOO_LARGE); + } + + if (name[0] != ':') { + ++stream->request_headers_added; + if (stream->request_headers_added + > stream->session->s->limit_req_fields) { + /* too many header lines */ + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, stream->session->c, + "h2_stream(%ld-%d): too many header lines", + stream->session->id, stream->id); + return h2_stream_set_error(stream, + HTTP_REQUEST_HEADER_FIELDS_TOO_LARGE); + } + } + } + if (h2_stream_is_scheduled(stream)) { return h2_request_add_trailer(stream->request, stream->pool, name, nlen, value, vlen); @@ -321,6 +355,11 @@ apr_status_t h2_stream_schedule(h2_stream *stream, int eos, int push_enabled, close_input(stream); } + if (stream->response) { + /* already have a resonse, probably a HTTP error code */ + return h2_mplx_process(stream->session->mplx, stream, cmp, ctx); + } + /* Seeing the end-of-headers, we have everything we need to * start processing it. */ @@ -510,6 +549,18 @@ apr_status_t h2_stream_set_response(h2_stream *stream, h2_response *response, return status; } +apr_status_t h2_stream_set_error(h2_stream *stream, int http_status) +{ + h2_response *response; + + if (stream->submitted) { + return APR_EINVAL; + } + response = h2_response_die(stream->id, http_status, stream->request, + stream->pool); + return h2_stream_set_response(stream, response, NULL); +} + static const apr_size_t DATA_CHUNK_SIZE = ((16*1024) - 100 - 9); apr_status_t h2_stream_out_prepare(h2_stream *stream, diff --git a/mod_http2/h2_stream.h b/mod_http2/h2_stream.h index 33f28f6e..84f97171 100644 --- a/mod_http2/h2_stream.h +++ b/mod_http2/h2_stream.h @@ -49,7 +49,8 @@ struct h2_stream { apr_pool_t *pool; /* the memory pool for this stream */ struct h2_request *request; /* the request made in this stream */ struct h2_bucket_beam *input; - + int request_headers_added; /* number of request headers added */ + struct h2_response *response; struct h2_bucket_beam *output; apr_bucket_brigade *buffer; @@ -188,6 +189,11 @@ apr_status_t h2_stream_set_response(h2_stream *stream, struct h2_response *response, struct h2_bucket_beam *output); +/** + * Set the HTTP error status as response. + */ +apr_status_t h2_stream_set_error(h2_stream *stream, int http_status); + /** * Do a speculative read on the stream output to determine the * amount of data that can be read. diff --git a/mod_http2/h2_task.c b/mod_http2/h2_task.c index 92029d89..36073f77 100644 --- a/mod_http2/h2_task.c +++ b/mod_http2/h2_task.c @@ -625,7 +625,7 @@ void h2_task_set_io_blocking(h2_task *task, int blocking) task->blocking = blocking; } -apr_status_t h2_task_do(h2_task *task) +apr_status_t h2_task_do(h2_task *task, apr_thread_t *thread) { AP_DEBUG_ASSERT(task); @@ -659,6 +659,7 @@ apr_status_t h2_task_do(h2_task *task) ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, task->c, "h2_task(%s): process connection", task->id); + task->c->current_thread = thread; ap_run_process_connection(task->c); if (task->frozen) { diff --git a/mod_http2/h2_task.h b/mod_http2/h2_task.h index 454bc376..c9280388 100644 --- a/mod_http2/h2_task.h +++ b/mod_http2/h2_task.h @@ -101,7 +101,7 @@ h2_task *h2_task_create(conn_rec *c, const struct h2_request *req, void h2_task_destroy(h2_task *task); -apr_status_t h2_task_do(h2_task *task); +apr_status_t h2_task_do(h2_task *task, apr_thread_t *thread); void h2_task_set_response(h2_task *task, struct h2_response *response); diff --git a/mod_http2/h2_util.c b/mod_http2/h2_util.c index e6fe4596..4cfa1649 100644 --- a/mod_http2/h2_util.c +++ b/mod_http2/h2_util.c @@ -1465,7 +1465,7 @@ int h2_util_frame_print(const nghttp2_frame *frame, char *buffer, size_t maxlen) } case NGHTTP2_GOAWAY: { size_t len = (frame->goaway.opaque_data_len < s_len)? - frame->goaway.opaque_data_len : s_len-1; + 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', " diff --git a/mod_http2/h2_version.h b/mod_http2/h2_version.h index 13cd3df2..971b0766 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.5.3" +#define MOD_HTTP2_VERSION "1.5.5" /** * @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 0x010503 +#define MOD_HTTP2_VERSION_NUM 0x010505 #endif /* mod_h2_h2_version_h */ diff --git a/mod_http2/h2_worker.c b/mod_http2/h2_worker.c index e394298e..44feac14 100644 --- a/mod_http2/h2_worker.c +++ b/mod_http2/h2_worker.c @@ -43,7 +43,7 @@ static void* APR_THREAD_FUNC execute(apr_thread_t *thread, void *wctx) worker->get_next(worker, worker->ctx, &task, &sticky); while (task) { - h2_task_do(task); + h2_task_do(task, thread); /* report the task done and maybe get another one from the same * mplx (= master connection), if we can be sticky. */ diff --git a/mod_http2/mod_proxy_http2.c b/mod_http2/mod_proxy_http2.c index a083a927..d551f24e 100644 --- a/mod_http2/mod_proxy_http2.c +++ b/mod_http2/mod_proxy_http2.c @@ -259,7 +259,7 @@ static apr_status_t add_request(h2_proxy_session *session, request_rec *r) apr_table_setn(r->notes, "proxy-source-port", apr_psprintf(r->pool, "%hu", ctx->p_conn->connection->local_addr->port)); status = h2_proxy_session_submit(session, url, r); - if (status != OK) { + if (status != APR_SUCCESS) { ap_log_cerror(APLOG_MARK, APLOG_ERR, status, r->connection, APLOGNO(03351) "pass request body failed to %pI (%s) from %s (%s)", ctx->p_conn->addr, ctx->p_conn->hostname ?