diff --git a/modules/http2/h2_stream.c b/modules/http2/h2_stream.c index a1c6b6cc069..44cc4f49b03 100644 --- a/modules/http2/h2_stream.c +++ b/modules/http2/h2_stream.c @@ -763,7 +763,7 @@ apr_status_t h2_stream_add_header(h2_stream *stream, if (name[0] == ':') { if (vlen > APR_INT32_MAX || (int)vlen > session->s->limit_req_line) { /* pseudo header: approximation of request line size check */ - if (!h2_stream_is_ready(stream)) { + if (!stream->request_headers_failed) { ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, session->c1, H2_STRM_LOG(APLOGNO(10178), stream, "Request pseudo header exceeds " @@ -810,7 +810,7 @@ apr_status_t h2_stream_add_header(h2_stream *stream, if (APR_EINVAL == status) { /* header too long */ - if (!h2_stream_is_ready(stream) && !stream->request_headers_failed) { + if (!stream->request_headers_failed) { ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, session->c1, H2_STRM_LOG(APLOGNO(10180), stream, "Request header exceeds LimitRequestFieldSize(%d): %.*s"), @@ -829,7 +829,7 @@ apr_status_t h2_stream_add_header(h2_stream *stream, h2_stream_rst(stream, H2_ERR_ENHANCE_YOUR_CALM); return APR_ECONNRESET; } - if (!h2_stream_is_ready(stream)) { + if (!stream->request_headers_failed) { ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, session->c1, H2_STRM_LOG(APLOGNO(10181), stream, "Number of request headers " "exceeds LimitRequestFields(%d)"), @@ -889,7 +889,7 @@ apr_status_t h2_stream_end_headers(h2_stream *stream, int eos, size_t raw_bytes) ctx.failed_key = NULL; apr_table_do(table_check_val_len, &ctx, req->headers, NULL); if (ctx.failed_key) { - if (!h2_stream_is_ready(stream)) { + if (!stream->request_headers_failed) { ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, stream->session->c1, H2_STRM_LOG(APLOGNO(10230), stream,"Request header exceeds " "LimitRequestFieldSize: %.*s"), diff --git a/test/modules/http2/test_111_header_limit_log.py b/test/modules/http2/test_111_header_limit_log.py new file mode 100644 index 00000000000..de91020b379 --- /dev/null +++ b/test/modules/http2/test_111_header_limit_log.py @@ -0,0 +1,50 @@ +import re + +import pytest + +from .env import H2Conf, H2TestEnv + +# h2_stream_add_header() logs a limit violation once per stream, not once per +# offending header. The guard used to be h2_stream_is_ready(), but +# set_error_response() only sets rtmp->http_status these days and never makes +# the stream "ready" while headers are still being read, so every oversized +# header logged another line. +# AH10181 is logged from the "too many headers" branch, whose only guard was +# h2_stream_is_ready(). Each header past LimitRequestFields hits it again. +LOGNO = "AH10181" +LIMIT = 5 +NHEADERS = 25 + + +@pytest.mark.skipif(condition=H2TestEnv.is_unsupported(), reason="mod_http2 not supported here") +class TestHeaderLimitLog: + + @pytest.fixture(autouse=True, scope='class') + def _class_scope(self, env): + conf = H2Conf(env, extras={ + f"test1.{env.http_tld}": [ + f"LimitRequestFields {LIMIT}", + "LogLevel http2:info", + ], + }) + conf.add_vhost_test1() + conf.install() + assert env.apache_restart() == 0 + + def test_h2_111_01(self, env): + env.httpd_error_log.clear_log() + # Many more headers than LimitRequestFields allows. + options = ["--http2"] + for i in range(NHEADERS): + options.extend(["-H", f"X-Extra-{i}: v"]) + r = env.curl_get(env.mkurl("https", "test1", "/index.html"), 5, + options=options) + assert r.exit_code == 0, f"curl failed: {r.stderr}" + assert r.response["status"] == 431, \ + f"expected 431, got {r.response['status']}" + + with open(env.httpd_error_log.path) as fd: + hits = [ln for ln in fd if LOGNO in ln] + assert len(hits) == 1, \ + f"{LOGNO} logged {len(hits)} times for {NHEADERS} headers over " \ + f"LimitRequestFields {LIMIT}, expected once:\n" + "".join(hits)