Test coverage for logging http2 header limit violations once (#666)

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"),

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)