From ff2c0232f8078d423c9afca5af3830a8edfc5fe9 Mon Sep 17 00:00:00 2001 From: Stefan Eissing Date: Tue, 19 Jan 2016 12:42:34 +0000 Subject: [PATCH] bytes read/written on slave connections are reported to mod_logio, fixes PR 58871 git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1725496 13f79535-47bb-0310-9956-ffa450edef68 --- CHANGES | 56 ++-------------------------------- modules/http2/h2_task.c | 16 ++++++++-- modules/http2/h2_task.h | 9 ++++++ modules/http2/h2_task_input.c | 20 +++++++----- modules/http2/h2_task_input.h | 4 +-- modules/http2/h2_task_output.c | 55 +++++++++++++++++++++------------ modules/http2/h2_task_output.h | 3 +- modules/http2/h2_util.c | 34 +++++++++++++++++++++ modules/http2/h2_util.h | 10 ++++++ modules/http2/h2_version.h | 4 +-- modules/http2/mod_http2.c | 3 ++ 11 files changed, 127 insertions(+), 87 deletions(-) diff --git a/CHANGES b/CHANGES index 341e119c66..2ed95841f1 100644 --- a/CHANGES +++ b/CHANGES @@ -1,12 +1,11 @@ -*- coding: utf-8 -*- Changes with Apache 2.5.0 + *) mod_http2: bytes read/written on slave connections are reported via the + optional mod_logio functions. Fixes PR 58871. + *) Added many log numbers to log statements that had none. - *) mod_http2: fixed compile issues re cc's with builtin log2n, fixed cache - digest calculation. [Stefan Eissing] - - pushed resources are kept. See directive H2PushDiarySize for managing this. *) core: Add expression support to SetHandler. [Eric Covener] @@ -19,20 +18,6 @@ Changes with Apache 2.5.0 is now logged at TRACE1 level to match the underlying core output filter severity. [Eric Covener] - *) mod_http2: connection how keep a "push diary" where hashes of already - pushed resources are kept. See directive H2PushDiarySize for managing this. - Push diaries can be initialized by clients via the "Cache-Digest" request - header. This carries a base64url encoded. compressed Golomb set as described - in https://datatracker.ietf.org/doc/draft-kazuho-h2-cache-digest/ - Introduced a status handler for HTTP/2 connections, giving various counters - and statistics about the current connection, plus its cache digest value - in a JSON record. Not a replacement for more HTTP/2 in the server status. - Configured as - - SetHandler http2-status - - [Stefan Eissing] - *) mod_rewrite: Avoid looping on relative substitutions that result in the same filename we started with. PR 58854. [Eric Covener] @@ -40,12 +25,6 @@ Changes with Apache 2.5.0 *) mime.types: add common extension "m4a" for MPEG 4 Audio. PR 57895 [Dylan Millikin ] - *) mod_http2: async reading for http2 connections disabled for now. Fixed - flushing of last GOAWAY frame. Fixed calculation of last stream id - accepted as described in rfc7540. Reading in KEEPALIVE state now - correctly show in scoreboard. Fixed possible race in connection - shutdown after review by Ylavic. [Stefan Eissing] - *) mod_ssl: Save some TLS record (application data) fragmentations by including the last and subsequent suitable buckets when coalescing. [Yann Ylavic] @@ -54,35 +33,6 @@ Changes with Apache 2.5.0 is received from an origin server in multiple batches and forwarded by mod_proxy. [Yann Ylavic] - *) mod_http2: Fixed segfault on connection shutdown, callback ran into a semi - dismantled session. Added support for experimental accept-push-policy draft - (https://tools.ietf.org/html/draft-ruellan-http-accept-push-policy-00). Clients - may now influence server pushes by sending accept-push-policy headers. - [Stefan Eissing] - - *) mod_http2: On async MPMs (event), idle HTTP/2 connections will enter KEEPALIVE - state and become eligible for MPM cleanup under load. Rewrote connection - state handling. Defaults for H2KeepAliveTimeout shortened. Cleaned up logging. - Improved scoreboard updates for http2 master threads. - [Stefan Eissing] - - *) mod_http2: new r->subprocess_env variables HTTP2 and H2PUSH, set to "on" - when available for request. - [Stefan Eissing] - - *) mod_http2: adding new config directives and the implementation behind - them: H2Timeout, H2KeepAliveTimeout, H2StreamTimeout. Documentation in - the http2 manual. - [Stefan Eissing] - - *) mod_http2: when running in async mpm processing, mod_http2 will cease - processing on idle connections (e.g. no open streams) back to the mpm. - [Stefan Eissing] - - *) mod_http2: fixed bug in input window size calculation by moving chunked - request body encoding into later stage of processing. - [Stefan Eissing] - *) mod_proxy_fdpass: Fix AH01153 error when using the default configuration. In earlier version of httpd, you can explicitelly set the 'flusher' parameter to 'flush' as a workaround. (i.e. flusher=flush) diff --git a/modules/http2/h2_task.c b/modules/http2/h2_task.c index fb7ccc3a18..9525cc15ed 100644 --- a/modules/http2/h2_task.c +++ b/modules/http2/h2_task.c @@ -92,6 +92,9 @@ static const char *const mod_ssl[] = { "mod_ssl.c", NULL}; static int h2_task_pre_conn(conn_rec* c, void *arg); static int h2_task_process_conn(conn_rec* c); +APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_task_logio_add_bytes_in; +APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_task_logio_add_bytes_out; + void h2_task_register_hooks(void) { /* This hook runs on new connections before mod_ssl has a say. @@ -118,6 +121,15 @@ void h2_task_register_hooks(void) NULL, AP_FTYPE_PROTOCOL); } +/* post config init */ +apr_status_t h2_task_init(apr_pool_t *pool, server_rec *s) +{ + h2_task_logio_add_bytes_in = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_in); + h2_task_logio_add_bytes_out = APR_RETRIEVE_OPTIONAL_FN(ap_logio_add_bytes_out); + + return APR_SUCCESS; +} + static int h2_task_pre_conn(conn_rec* c, void *arg) { h2_ctx *ctx; @@ -169,8 +181,8 @@ apr_status_t h2_task_do(h2_task *task, conn_rec *c, apr_thread_cond_t *cond, { AP_DEBUG_ASSERT(task); task->io = cond; - task->input = h2_task_input_create(task, c->pool, c->bucket_alloc); - task->output = h2_task_output_create(task, c->pool); + task->input = h2_task_input_create(task, c); + task->output = h2_task_output_create(task, c); ap_process_connection(c, socket); diff --git a/modules/http2/h2_task.h b/modules/http2/h2_task.h index 08ce6c093a..ce17f85167 100644 --- a/modules/http2/h2_task.h +++ b/modules/http2/h2_task.h @@ -16,6 +16,8 @@ #ifndef __mod_h2__h2_task__ #define __mod_h2__h2_task__ +#include + /** * A h2_task fakes a HTTP/1.1 request from the data in a HTTP/2 stream * (HEADER+CONT.+DATA) the module recieves. @@ -67,5 +69,12 @@ apr_status_t h2_task_do(h2_task *task, conn_rec *c, struct apr_thread_cond_t *cond, apr_socket_t *socket); void h2_task_register_hooks(void); +/* + * One time, post config intialization. + */ +apr_status_t h2_task_init(apr_pool_t *pool, server_rec *s); + +extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_in) *h2_task_logio_add_bytes_in; +extern APR_OPTIONAL_FN_TYPE(ap_logio_add_bytes_out) *h2_task_logio_add_bytes_out; #endif /* defined(__mod_h2__h2_task__) */ diff --git a/modules/http2/h2_task_input.c b/modules/http2/h2_task_input.c index 992e956982..16ef3c8d14 100644 --- a/modules/http2/h2_task_input.c +++ b/modules/http2/h2_task_input.c @@ -43,29 +43,29 @@ static int ser_header(void *ctx, const char *name, const char *value) return 1; } -h2_task_input *h2_task_input_create(h2_task *task, apr_pool_t *pool, - apr_bucket_alloc_t *bucket_alloc) +h2_task_input *h2_task_input_create(h2_task *task, conn_rec *c) { - h2_task_input *input = apr_pcalloc(pool, sizeof(h2_task_input)); + h2_task_input *input = apr_pcalloc(c->pool, sizeof(h2_task_input)); if (input) { + input->c = c; input->task = task; input->bb = NULL; if (task->ser_headers) { - ap_log_perror(APLOG_MARK, APLOG_TRACE1, 0, pool, + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c, "h2_task_input(%s): serialize request %s %s", task->id, task->request->method, task->request->path); - input->bb = apr_brigade_create(pool, bucket_alloc); + input->bb = apr_brigade_create(c->pool, c->bucket_alloc); apr_brigade_printf(input->bb, NULL, NULL, "%s %s HTTP/1.1\r\n", task->request->method, task->request->path); apr_table_do(ser_header, input, task->request->headers, NULL); apr_brigade_puts(input->bb, NULL, NULL, "\r\n"); if (input->task->input_eos) { - APR_BRIGADE_INSERT_TAIL(input->bb, apr_bucket_eos_create(bucket_alloc)); + APR_BRIGADE_INSERT_TAIL(input->bb, apr_bucket_eos_create(c->bucket_alloc)); } } else if (!input->task->input_eos) { - input->bb = apr_brigade_create(pool, bucket_alloc); + input->bb = apr_brigade_create(c->pool, c->bucket_alloc); } else { /* We do not serialize and have eos already, no need to @@ -130,7 +130,7 @@ apr_status_t h2_task_input_read(h2_task_input *input, (long)readbytes, (long)bblen); /* Although we sometimes get called with APR_NONBLOCK_READs, - we seem to fill our buffer blocking. Otherwise we get EAGAIN, + we need to fill our buffer blocking. Otherwise we get EAGAIN, return that to our caller and everyone throws up their hands, never calling us again. */ status = h2_mplx_in_read(input->task->mplx, APR_BLOCK_READ, @@ -150,9 +150,13 @@ apr_status_t h2_task_input_read(h2_task_input *input, if ((bblen == 0) && (block == APR_NONBLOCK_READ)) { return h2_util_has_eos(input->bb, -1)? APR_EOF : APR_EAGAIN; } + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, status, f->c, "h2_task_input(%s): mplx in read, %ld bytes in brigade", input->task->id, (long)bblen); + if (h2_task_logio_add_bytes_in) { + h2_task_logio_add_bytes_in(f->c, bblen); + } } ap_log_cerror(APLOG_MARK, APLOG_TRACE1, status, f->c, diff --git a/modules/http2/h2_task_input.h b/modules/http2/h2_task_input.h index ed0a99faba..bfc01f580f 100644 --- a/modules/http2/h2_task_input.h +++ b/modules/http2/h2_task_input.h @@ -26,13 +26,13 @@ struct h2_task; typedef struct h2_task_input h2_task_input; struct h2_task_input { + conn_rec *c; struct h2_task *task; apr_bucket_brigade *bb; }; -h2_task_input *h2_task_input_create(struct h2_task *task, apr_pool_t *pool, - apr_bucket_alloc_t *bucket_alloc); +h2_task_input *h2_task_input_create(struct h2_task *task, conn_rec *c); void h2_task_input_destroy(h2_task_input *input); diff --git a/modules/http2/h2_task_output.c b/modules/http2/h2_task_output.c index 2bbac1c4ce..340b82d94d 100644 --- a/modules/http2/h2_task_output.c +++ b/modules/http2/h2_task_output.c @@ -34,14 +34,14 @@ #include "h2_util.h" -h2_task_output *h2_task_output_create(h2_task *task, apr_pool_t *pool) +h2_task_output *h2_task_output_create(h2_task *task, conn_rec *c) { - h2_task_output *output = apr_pcalloc(pool, sizeof(h2_task_output)); - + h2_task_output *output = apr_pcalloc(c->pool, sizeof(h2_task_output)); if (output) { + output->c = c; output->task = task; output->state = H2_TASK_OUT_INIT; - output->from_h1 = h2_from_h1_create(task->stream_id, pool); + output->from_h1 = h2_from_h1_create(task->stream_id, c->pool); if (!output->from_h1) { return NULL; } @@ -57,6 +57,23 @@ void h2_task_output_destroy(h2_task_output *output) } } +static apr_table_t *get_trailers(h2_task_output *output) +{ + if (!output->trailers_passed) { + h2_response *response = h2_from_h1_get_response(output->from_h1); + if (response && response->trailers) { + output->trailers_passed = 1; + if (h2_task_logio_add_bytes_out) { + /* counter trailers as if we'd do a HTTP/1.1 serialization */ + h2_task_logio_add_bytes_out(output->c, + h2_util_table_bytes(response->trailers, 3)+1); + } + return response->trailers; + } + } + return NULL; +} + static apr_status_t open_if_needed(h2_task_output *output, ap_filter_t *f, apr_bucket_brigade *bb) { @@ -67,8 +84,7 @@ static apr_status_t open_if_needed(h2_task_output *output, ap_filter_t *f, if (!response) { if (f) { /* This happens currently when ap_die(status, r) is invoked - * by a read request filter. - */ + * by a read request filter. */ ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, f->c, APLOGNO(03204) "h2_task_output(%s): write without response " "for %s %s %s", @@ -83,25 +99,21 @@ static apr_status_t open_if_needed(h2_task_output *output, ap_filter_t *f, return APR_ECONNABORTED; } - output->trailers_passed = !!response->trailers; + if (h2_task_logio_add_bytes_out) { + /* counter headers as if we'd do a HTTP/1.1 serialization */ + /* TODO: counter a virtual status line? */ + apr_off_t bytes_written; + apr_brigade_length(bb, 0, &bytes_written); + bytes_written += h2_util_table_bytes(response->headers, 3)+1; + h2_task_logio_add_bytes_out(f->c, bytes_written); + } + get_trailers(output); return h2_mplx_out_open(output->task->mplx, output->task->stream_id, response, f, bb, output->task->io); } return APR_EOF; } -static apr_table_t *get_trailers(h2_task_output *output) -{ - if (!output->trailers_passed) { - h2_response *response = h2_from_h1_get_response(output->from_h1); - if (response && response->trailers) { - output->trailers_passed = 1; - return response->trailers; - } - } - return NULL; -} - void h2_task_output_close(h2_task_output *output) { open_if_needed(output, NULL, NULL); @@ -142,6 +154,11 @@ apr_status_t h2_task_output_write(h2_task_output *output, ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, f->c, "h2_task_output(%s): write brigade", output->task->id); + if (h2_task_logio_add_bytes_out) { + apr_off_t bytes_written; + apr_brigade_length(bb, 0, &bytes_written); + h2_task_logio_add_bytes_out(f->c, bytes_written); + } return h2_mplx_out_write(output->task->mplx, output->task->stream_id, f, bb, get_trailers(output), output->task->io); } diff --git a/modules/http2/h2_task_output.h b/modules/http2/h2_task_output.h index 3e3b857bc1..eed1f0123c 100644 --- a/modules/http2/h2_task_output.h +++ b/modules/http2/h2_task_output.h @@ -35,13 +35,14 @@ typedef enum { typedef struct h2_task_output h2_task_output; struct h2_task_output { + conn_rec *c; struct h2_task *task; h2_task_output_state_t state; struct h2_from_h1 *from_h1; unsigned int trailers_passed : 1; }; -h2_task_output *h2_task_output_create(struct h2_task *task, apr_pool_t *pool); +h2_task_output *h2_task_output_create(struct h2_task *task, conn_rec *c); void h2_task_output_destroy(h2_task_output *output); diff --git a/modules/http2/h2_util.c b/modules/http2/h2_util.c index 8db68a2503..3edfe7c635 100644 --- a/modules/http2/h2_util.c +++ b/modules/http2/h2_util.c @@ -230,6 +230,40 @@ const char *h2_util_first_token_match(apr_pool_t *pool, const char *s, return NULL; } + +/******************************************************************************* + * h2_util for apt_table_t + ******************************************************************************/ + +typedef struct { + apr_size_t bytes; + apr_size_t pair_extra; +} table_bytes_ctx; + +static int count_bytes(void *x, const char *key, const char *value) +{ + table_bytes_ctx *ctx = x; + if (key) { + ctx->bytes += strlen(key); + } + if (value) { + ctx->bytes += strlen(value); + } + ctx->bytes += ctx->pair_extra; + return 1; +} + +apr_size_t h2_util_table_bytes(apr_table_t *t, apr_size_t pair_extra) +{ + table_bytes_ctx ctx; + + ctx.bytes = 0; + ctx.pair_extra = pair_extra; + apr_table_do(count_bytes, &ctx, t, NULL); + return ctx.bytes; +} + + /******************************************************************************* * h2_util for bucket brigades ******************************************************************************/ diff --git a/modules/http2/h2_util.h b/modules/http2/h2_util.h index 1730e00cc9..6d86f76a2a 100644 --- a/modules/http2/h2_util.h +++ b/modules/http2/h2_util.h @@ -28,6 +28,16 @@ size_t h2_util_header_print(char *buffer, size_t maxlen, void h2_util_camel_case_header(char *s, size_t len); +/** + * Count the bytes that all key/value pairs in a table have + * in length (exlucding terminating 0s), plus additional extra per pair. + * + * @param t the table to inspect + * @param pair_extra the extra amount to add per pair + * @return the number of bytes all key/value pairs have + */ +apr_size_t h2_util_table_bytes(apr_table_t *t, apr_size_t pair_extra); + int h2_req_ignore_header(const char *name, size_t len); int h2_req_ignore_trailer(const char *name, size_t len); void h2_req_strip_ignored_header(apr_table_t *headers); diff --git a/modules/http2/h2_version.h b/modules/http2/h2_version.h index b6a74e83e6..4de6aa4cb6 100644 --- a/modules/http2/h2_version.h +++ b/modules/http2/h2_version.h @@ -26,7 +26,7 @@ * @macro * Version number of the http2 module as c string */ -#define MOD_HTTP2_VERSION "1.2.1" +#define MOD_HTTP2_VERSION "1.2.3-DEV" /** * @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 0x010201 +#define MOD_HTTP2_VERSION_NUM 0x010203 #endif /* mod_h2_h2_version_h */ diff --git a/modules/http2/mod_http2.c b/modules/http2/mod_http2.c index 41cde35f86..06b0b7799a 100644 --- a/modules/http2/mod_http2.c +++ b/modules/http2/mod_http2.c @@ -109,6 +109,9 @@ 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_task_init(p, s); + } return status; } -- 2.40.0