From ac622813b2e8f2546b7a79a63a11dcbdf3a3bd0f Mon Sep 17 00:00:00 2001 From: Yann Ylavic Date: Fri, 7 Jul 2023 08:21:21 +0000 Subject: [PATCH] pytests: Ignore log errors/warnings per function. It's easier to control errors at the function scope and it avoids ignored errors/warnings to propagate to the following tests (i.e. mask further unexpected errors). github: closes #371 git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1910844 13f79535-47bb-0310-9956-ffa450edef68 --- test/conftest.py | 16 ++ test/modules/core/conftest.py | 15 -- test/modules/core/test_001_encoding.py | 41 ++--- test/modules/http1/conftest.py | 11 -- test/modules/http1/env.py | 8 - test/modules/http1/test_003_get.py | 1 - test/modules/http1/test_004_post.py | 1 - test/modules/http1/test_006_unsafe.py | 172 +++++++++--------- test/modules/http1/test_007_strict.py | 25 +-- test/modules/http2/conftest.py | 13 +- test/modules/http2/env.py | 29 --- test/modules/http2/test_007_ssi.py | 1 - test/modules/http2/test_100_conn_reuse.py | 12 ++ test/modules/http2/test_101_ssl_reneg.py | 46 +++++ test/modules/http2/test_102_require.py | 6 + test/modules/http2/test_105_timeout.py | 14 ++ test/modules/http2/test_106_shutdown.py | 8 +- test/modules/http2/test_200_header_invalid.py | 22 +++ test/modules/http2/test_203_rfc9113.py | 24 ++- test/modules/http2/test_500_proxy.py | 12 ++ test/modules/http2/test_800_websockets.py | 1 - test/modules/md/conftest.py | 40 +--- test/modules/md/test_300_conf_validate.py | 71 +++++++- test/modules/md/test_702_auto.py | 54 ++++++ test/modules/md/test_720_wildcard.py | 28 +++ test/modules/md/test_730_static.py | 7 + test/modules/md/test_740_acme_errors.py | 18 ++ test/modules/md/test_741_setup_errors.py | 10 + test/modules/md/test_750_eab.py | 90 +++++++++ test/modules/md/test_780_tailscale.py | 12 ++ test/modules/md/test_790_failover.py | 18 ++ test/modules/md/test_900_notify.py | 14 ++ test/modules/md/test_901_message.py | 32 +++- test/modules/md/test_920_status.py | 6 + test/modules/proxy/conftest.py | 20 -- test/modules/proxy/env.py | 1 - test/modules/proxy/test_02_unix.py | 6 + test/modules/tls/conftest.py | 6 - test/modules/tls/test_03_sni.py | 18 ++ test/modules/tls/test_06_ciphers.py | 14 +- test/modules/tls/test_14_proxy_ssl.py | 7 + test/modules/tls/test_15_proxy_tls.py | 8 +- test/pyhttpd/env.py | 7 + test/pyhttpd/log.py | 165 ++++++++--------- 44 files changed, 762 insertions(+), 368 deletions(-) diff --git a/test/conftest.py b/test/conftest.py index 2ae35f34ed9..ac0a7c553d8 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -23,9 +23,25 @@ def pytest_generate_tests(metafunc): metafunc.fixturenames.append('tmp_ct') metafunc.parametrize('repeat', range(count)) + @pytest.fixture(autouse=True, scope="function") def _function_scope(env, request): env.set_current_test_name(request.node.name) yield + env.check_error_log() env.set_current_test_name(None) + +@pytest.fixture(autouse=True, scope="module") +def _module_scope(env): + yield + env.check_error_log() + + +@pytest.fixture(autouse=True, scope="package") +def _package_scope(env): + env.httpd_error_log.clear_ignored_matches() + env.httpd_error_log.clear_ignored_lognos() + yield + assert env.apache_stop() == 0 + env.check_error_log() diff --git a/test/modules/core/conftest.py b/test/modules/core/conftest.py index cf670bbea18..22906efbb04 100644 --- a/test/modules/core/conftest.py +++ b/test/modules/core/conftest.py @@ -28,18 +28,3 @@ def env(pytestconfig) -> CoreTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - env.httpd_error_log.set_ignored_lognos([ - 'AH10244', # core: invalid URI path - 'AH01264', # mod_cgid script not found - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - diff --git a/test/modules/core/test_001_encoding.py b/test/modules/core/test_001_encoding.py index b7ffbaa8429..a3b24d04710 100644 --- a/test/modules/core/test_001_encoding.py +++ b/test/modules/core/test_001_encoding.py @@ -1,12 +1,11 @@ import pytest +from typing import List, Optional from pyhttpd.conf import HttpdConf class TestEncoding: - EXP_AH10244_ERRS = 0 - @pytest.fixture(autouse=True, scope='class') def _class_scope(self, env): conf = HttpdConf(env, extras={ @@ -57,29 +56,29 @@ def test_core_001_03(self, env, path): assert r.response["status"] == 200 # check path traversals - @pytest.mark.parametrize(["path", "status"], [ - ["/../echo.py", 400], - ["/nothing/../../echo.py", 400], - ["/cgi-bin/../../echo.py", 400], - ["/nothing/%2e%2e/%2e%2e/echo.py", 400], - ["/cgi-bin/%2e%2e/%2e%2e/echo.py", 400], - ["/nothing/%%32%65%%32%65/echo.py", 400], - ["/cgi-bin/%%32%65%%32%65/echo.py", 400], - ["/nothing/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400], - ["/cgi-bin/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400], - ["/nothing/%25%32%65%25%32%65/echo.py", 404], - ["/cgi-bin/%25%32%65%25%32%65/echo.py", 404], - ["/nothing/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404], - ["/cgi-bin/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404], + @pytest.mark.parametrize(["path", "status", "lognos"], [ + ["/../echo.py", 400, ["AH10244"]], + ["/nothing/../../echo.py", 400, ["AH10244"]], + ["/cgi-bin/../../echo.py", 400, ["AH10244"]], + ["/nothing/%2e%2e/%2e%2e/echo.py", 400, ["AH10244"]], + ["/cgi-bin/%2e%2e/%2e%2e/echo.py", 400, ["AH10244"]], + ["/nothing/%%32%65%%32%65/echo.py", 400, ["AH10244"]], + ["/cgi-bin/%%32%65%%32%65/echo.py", 400, ["AH10244"]], + ["/nothing/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400, ["AH10244"]], + ["/cgi-bin/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400, ["AH10244"]], + ["/nothing/%25%32%65%25%32%65/echo.py", 404, ["AH01264"]], + ["/cgi-bin/%25%32%65%25%32%65/echo.py", 404, ["AH01264"]], + ["/nothing/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404, ["AH01264"]], + ["/cgi-bin/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404, ["AH01264"]], ]) - def test_core_001_04(self, env, path, status): + def test_core_001_04(self, env, path, status, lognos: Optional[List[str]]): url = env.mkurl("https", "test1", path) r = env.curl_get(url) assert r.response["status"] == status - if status == 400: - TestEncoding.EXP_AH10244_ERRS += 1 - # the log will have a core:err about invalid URI path - + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) + # check handling of %2f url encodings that are not decoded by default @pytest.mark.parametrize(["host", "path", "status"], [ ["test1", "/006%2f006.css", 404], diff --git a/test/modules/http1/conftest.py b/test/modules/http1/conftest.py index 0ebb4391298..33a16a11704 100644 --- a/test/modules/http1/conftest.py +++ b/test/modules/http1/conftest.py @@ -34,14 +34,3 @@ def env(pytestconfig) -> H1TestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - diff --git a/test/modules/http1/env.py b/test/modules/http1/env.py index 5e395f31a8d..e2df1a561f2 100644 --- a/test/modules/http1/env.py +++ b/test/modules/http1/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any @@ -61,13 +60,6 @@ def __init__(self, pytestconfig=None): super().__init__(pytestconfig=pytestconfig) self.add_httpd_log_modules(["http", "core"]) - self.httpd_error_log.set_ignored_lognos([ - 'AH00135', # unsafe/strict tests send invalid methods - 'AH02430', # test of invalid chars in response headers - ]) - self.httpd_error_log.add_ignored_patterns([ - ]) - def setup_httpd(self, setup: HttpdTestSetup = None): super().setup_httpd(setup=H1TestSetup(env=self)) diff --git a/test/modules/http1/test_003_get.py b/test/modules/http1/test_003_get.py index 21fd4ef5bf6..1cd5917de62 100644 --- a/test/modules/http1/test_003_get.py +++ b/test/modules/http1/test_003_get.py @@ -1,4 +1,3 @@ -import re import socket import pytest diff --git a/test/modules/http1/test_004_post.py b/test/modules/http1/test_004_post.py index d4d5edcbf58..005a8c2fbcf 100644 --- a/test/modules/http1/test_004_post.py +++ b/test/modules/http1/test_004_post.py @@ -3,7 +3,6 @@ import inspect import json import os -import re import sys import pytest diff --git a/test/modules/http1/test_006_unsafe.py b/test/modules/http1/test_006_unsafe.py index b6882292c2f..eb832175139 100644 --- a/test/modules/http1/test_006_unsafe.py +++ b/test/modules/http1/test_006_unsafe.py @@ -1,6 +1,6 @@ import re import socket -from typing import Optional +from typing import List, Optional import pytest @@ -23,88 +23,88 @@ def _class_scope(self, env): # 1: any HTTP success # 200-500: specific HTTP status code # None: HTTPD should drop connection without error message - @pytest.mark.parametrize(["intext", "status"], [ - ["GET / HTTP/1.0\r\n\r\n", 1], - ["GET / HTTP/1.0\n\n", 1], - ["get / HTTP/1.0\r\n\r\n", 501], - ["G ET / HTTP/1.0\r\n\r\n", 400], - ["G\0ET / HTTP/1.0\r\n\r\n", 400], - ["G/T / HTTP/1.0\r\n\r\n", 501], - ["GET /\0 HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\0\r\n\r\n", 400], - ["GET\f/ HTTP/1.0\r\n\r\n", 400], - ["GET\r/ HTTP/1.0\r\n\r\n", 400], - ["GET\t/ HTTP/1.0\r\n\r\n", 400], - ["GET / HTT/1.0\r\n\r\n", 0], - ["GET / HTTP/1.0\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/2.0\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/1.2\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/1.11\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/10.0\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/1.0 \r\nHost: localhost\r\n\r\n", 200], - ["GET / HTTP/1.0 x\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/\r\nHost: localhost\r\n\r\n", 0], - ["GET / HTTP/0.9\r\n\r\n", 0], - ["GET / HTTP/0.8\r\n\r\n", 0], - ["GET /\x01 HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo:bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo: b\0ar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo: b\x01ar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\n: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nX: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo bar:bash\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo :bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\n Foo:bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nF\x01o: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nF\ro: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nF\to: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFo: b\tar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFo: bar\r\r\n\r\n", 400], - ["GET / HTTP/1.0\r\r", None], - ["GET /\r\n", 90], - ["GET /#frag HTTP/1.0\r\n", 400], - ["GET / HTTP/1.0\r\nHost: localhost\r\nHost: localhost\r\n\r\n", 200], - ["GET http://017700000001/ HTTP/1.0\r\n\r\n", 200], - ["GET http://0x7f.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://127.0.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://127.01.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://%3127.0.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: localhost:80\r\nHost: localhost:80\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: localhost:80 x\r\n\r", 400], - ["GET http://localhost:80/ HTTP/1.0\r\n\r\n", 200], - ["GET http://localhost:80x/ HTTP/1.0\r\n\r\n", 400], - ["GET http://localhost:80:80/ HTTP/1.0\r\n\r\n", 400], - ["GET http://localhost::80/ HTTP/1.0\r\n\r\n", 400], - ["GET http://foo@localhost:80/ HTTP/1.0\r\n\r\n", 200], - ["GET http://[::1]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[::1:2]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd:1]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd::]/ HTTP/1.0\r\n\r\n", 400], - ["GET http://[4712:abcd::]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd]:8000/ HTTP/1.0\r\n\r\n", 1], - ["GET http://4713::abcd:8001/ HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nHost: [::1]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [::1:2]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd:1]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711:abcd::]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd]:8000\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: 4714::abcd:8001\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: abc\xa0\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: abc\\foo\r\n\r\n", 400], - ["GET http://foo/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://foo:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://[::1]:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://10.0.0.1:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: foo-bar.example.com\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: foo_bar.example.com\r\n\r\n", 200], - ["GET http://foo_bar/ HTTP/1.0\r\n\r\n", 200], + @pytest.mark.parametrize(["intext", "status", "lognos"], [ + ["GET / HTTP/1.0\r\n\r\n", 1, None], + ["GET / HTTP/1.0\n\n", 1, None], + ["get / HTTP/1.0\r\n\r\n", 501, ["AH00135"]], + ["G ET / HTTP/1.0\r\n\r\n", 400, None], + ["G\0ET / HTTP/1.0\r\n\r\n", 400, None], + ["G/T / HTTP/1.0\r\n\r\n", 501, ["AH00135"]], + ["GET /\0 HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\0\r\n\r\n", 400, None], + ["GET\f/ HTTP/1.0\r\n\r\n", 400, None], + ["GET\r/ HTTP/1.0\r\n\r\n", 400, None], + ["GET\t/ HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTT/1.0\r\n\r\n", 0, None], + ["GET / HTTP/1.0\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/2.0\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/1.2\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/1.11\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/10.0\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/1.0 \r\nHost: localhost\r\n\r\n", 200, None], + ["GET / HTTP/1.0 x\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/\r\nHost: localhost\r\n\r\n", 0, None], + ["GET / HTTP/0.9\r\n\r\n", 0, None], + ["GET / HTTP/0.8\r\n\r\n", 0, None], + ["GET /\x01 HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo:bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo: b\0ar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo: b\x01ar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\n: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nX: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo bar:bash\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo :bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\n Foo:bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nF\x01o: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nF\ro: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nF\to: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFo: b\tar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFo: bar\r\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\r", None, None], + ["GET /\r\n", 0, None], + ["GET /#frag HTTP/1.0\r\n", 400, None], + ["GET / HTTP/1.0\r\nHost: localhost\r\nHost: localhost\r\n\r\n", 200, None], + ["GET http://017700000001/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://0x7f.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://127.0.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://127.01.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://%3127.0.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: localhost:80\r\nHost: localhost:80\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: localhost:80 x\r\n\r", 400, None], + ["GET http://localhost:80/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://localhost:80x/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://localhost:80:80/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://localhost::80/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://foo@localhost:80/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://[::1]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[::1:2]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd:1]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd::]/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://[4712:abcd::,]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd]:8000/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://4713::abcd:8001/ HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nHost: [::1]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [::1:2]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd:1]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711:abcd::]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd]:8000\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: 4714::abcd:8001\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: abc\xa0\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: abc\\foo\r\n\r\n", 400, None], + ["GET http://foo/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://foo:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://[::1]:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://10.0.0.1:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: foo-bar.example.com\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: foo_bar.example.com\r\n\r\n", 200, None], + ["GET http://foo_bar/ HTTP/1.0\r\n\r\n", 200, None], ]) - def test_h1_006_01(self, env, intext, status: Optional[int]): + def test_h1_006_01(self, env, intext, status: Optional[int], lognos: Optional[List[str]]): with socket.create_connection(('localhost', int(env.http_port))) as sock: # on some OS, the server does not see our connection until there is # something incoming @@ -119,14 +119,16 @@ def test_h1_006_01(self, env, intext, status: Optional[int]): rlines = msg.splitlines() response = rlines[0] m = re.match(r'^HTTP/1.1 (\d+)\s+(\S+)', response) - assert m or status == 90, f"unrecognized response: {rlines}" + assert m or status == 0, f"unrecognized response: {rlines}" if status == 1: assert int(m.group(1)) >= 200 - elif status == 90: + elif status == 0: # headerless 0.9 response, yuk assert len(rlines) >= 1, f"{rlines}" elif status > 0: assert int(m.group(1)) == status, f"{rlines}" else: assert int(m.group(1)) >= 400, f"{rlines}" - + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) diff --git a/test/modules/http1/test_007_strict.py b/test/modules/http1/test_007_strict.py index 7eee027a6f2..7c52f685a83 100644 --- a/test/modules/http1/test_007_strict.py +++ b/test/modules/http1/test_007_strict.py @@ -1,6 +1,6 @@ import re import socket -from typing import Optional +from typing import List, Optional import pytest @@ -68,17 +68,17 @@ def test_h1_007_01(self, env, intext, status: Optional[int]): else: assert int(m.group(1)) >= 400, f"{rlines}" - @pytest.mark.parametrize(["hvalue", "expvalue", "status"], [ - ['"123"', '123', 200], - ['"123 "', '123 ', 200], # trailing space stays - ['"123\t"', '123\t', 200], # trailing tab stays - ['" 123"', '123', 200], # leading space is stripped - ['" 123"', '123', 200], # leading spaces are stripped - ['"\t123"', '123', 200], # leading tab is stripped - ['"expr=%{unescape:123%0A 123}"', '', 500], # illegal char - ['" \t "', '', 200], # just ws + @pytest.mark.parametrize(["hvalue", "expvalue", "status", "lognos"], [ + ['"123"', '123', 200, None], + ['"123 "', '123 ', 200, None], # trailing space stays + ['"123\t"', '123\t', 200, None], # trailing tab stays + ['" 123"', '123', 200, None], # leading space is stripped + ['" 123"', '123', 200, None], # leading spaces are stripped + ['"\t123"', '123', 200, None], # leading tab is stripped + ['"expr=%{unescape:123%0A 123}"', '', 500, ["AH02430"]], # illegal char + ['" \t "', '', 200, None], # just ws ]) - def test_h1_007_02(self, env, hvalue, expvalue, status): + def test_h1_007_02(self, env, hvalue, expvalue, status, lognos: Optional[List[str]]): hname = 'ap-test-007' conf = H1Conf(env, extras={ f'test1.{env.http_tld}': [ @@ -95,6 +95,9 @@ def test_h1_007_02(self, env, hvalue, expvalue, status): assert r.response["status"] == status if int(status) < 400: assert r.response["header"][hname] == expvalue + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) @pytest.mark.parametrize(["hvalue", "expvalue"], [ ['123', '123'], diff --git a/test/modules/http2/conftest.py b/test/modules/http2/conftest.py index 55d0c3a21e3..c6f8ddee711 100644 --- a/test/modules/http2/conftest.py +++ b/test/modules/http2/conftest.py @@ -30,11 +30,8 @@ def env(pytestconfig) -> H2TestEnv: @pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - +def _h2_package_scope(env): + env.httpd_error_log.add_ignored_lognos([ + 'AH10400', # warning that 'enablereuse' has not effect in certain configs + 'AH00045', # child did not exit in time, SIGTERM was sent + ]) diff --git a/test/modules/http2/env.py b/test/modules/http2/env.py index 34d196d6bd6..bac1a841be4 100644 --- a/test/modules/http2/env.py +++ b/test/modules/http2/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any @@ -85,34 +84,6 @@ def __init__(self, pytestconfig=None): CertificateSpec(domains=[f"noh2.{self.http_tld}"], key_type='rsa2048'), ]) - self.httpd_error_log.set_ignored_lognos([ - 'AH02032', - 'AH01276', - 'AH01630', - 'AH00135', - 'AH02261', # Re-negotiation handshake failed (our test_101) - 'AH03490', # scoreboard full, happens on limit tests - 'AH02429', # invalid chars in response header names, see test_h2_200 - 'AH02430', # invalid chars in response header values, see test_h2_200 - 'AH10373', # SSL errors on uncompleted handshakes, see test_h2_105 - 'AH01247', # mod_cgid sometimes freaks out on load tests - 'AH01110', # error by proxy reading response - 'AH10400', # warning that 'enablereuse' has not effect in certain configs test_h2_600 - 'AH00045', # child did not exit in time, SIGTERM was sent - ]) - self.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*malformed header from script \'hecho.py\': Bad header: x.*'), - re.compile(r'.*:tls_post_process_client_hello:.*'), - # OSSL 3 dropped the function name from the error description. Use the code instead: - # 0A0000C1 = no shared cipher -- Too restrictive SSLCipherSuite or using DSA server certificate? - re.compile(r'.*SSL Library Error: error:0A0000C1:.*'), - re.compile(r'.*:tls_process_client_certificate:.*'), - # OSSL 3 dropped the function name from the error description. Use the code instead: - # 0A0000C7 = peer did not return a certificate -- No CAs known to server for verification? - re.compile(r'.*SSL Library Error: error:0A0000C7:.*'), - re.compile(r'.*have incompatible TLS configurations.'), - ]) - def setup_httpd(self, setup: HttpdTestSetup = None): super().setup_httpd(setup=H2TestSetup(env=self)) diff --git a/test/modules/http2/test_007_ssi.py b/test/modules/http2/test_007_ssi.py index 97e38df0312..f5411bccd43 100644 --- a/test/modules/http2/test_007_ssi.py +++ b/test/modules/http2/test_007_ssi.py @@ -1,4 +1,3 @@ -import re import pytest from .env import H2Conf, H2TestEnv diff --git a/test/modules/http2/test_100_conn_reuse.py b/test/modules/http2/test_100_conn_reuse.py index 3ebac24d60b..103166fa301 100644 --- a/test/modules/http2/test_100_conn_reuse.py +++ b/test/modules/http2/test_100_conn_reuse.py @@ -48,6 +48,12 @@ def test_h2_100_04(self, env): hostname = ("noh2.%s" % env.http_tld) r = env.curl_get(url, 5, options=[ "-H", "Host:%s" % hostname ]) assert 421 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02032" # Hostname provided via SNI and hostname provided via HTTP have no compatible SSL setup + ] + ) # access an unknown vhost, after using ServerName in SNI def test_h2_100_05(self, env): @@ -55,3 +61,9 @@ def test_h2_100_05(self, env): hostname = ("unknown.%s" % env.http_tld) r = env.curl_get(url, 5, options=[ "-H", "Host:%s" % hostname ]) assert 421 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02032" # Hostname provided via SNI and hostname provided via HTTP have no compatible SSL setup + ] + ) diff --git a/test/modules/http2/test_101_ssl_reneg.py b/test/modules/http2/test_101_ssl_reneg.py index 66f2638a7b5..9b7f0eab2cb 100644 --- a/test/modules/http2/test_101_ssl_reneg.py +++ b/test/modules/http2/test_101_ssl_reneg.py @@ -56,6 +56,12 @@ def test_h2_101_01(self, env): assert 0 == r.exit_code, f"{r}" assert r.response assert 403 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01276" # No matching DirectoryIndex found + ] + ) # try to renegotiate the cipher, should fail with correct code def test_h2_101_02(self, env): @@ -66,6 +72,16 @@ def test_h2_101_02(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_post_process_client_hello:.*', + r'.*SSL Library Error:.*:SSL routines::no shared cipher.*' + ] + ) # try to renegotiate a client certificate from Location # needs to fail with correct code @@ -75,6 +91,16 @@ def test_h2_101_03(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_process_client_certificate:.*', + r'.*SSL Library Error:.*:SSL routines::peer did not return a certificate.*' + ] + ) # try to renegotiate a client certificate from Directory # needs to fail with correct code @@ -84,6 +110,16 @@ def test_h2_101_04(self, env): assert 0 != r.exit_code, f"{r}" assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_process_client_certificate:.*', + r'.*SSL Library Error:.*:SSL routines::peer did not return a certificate.*' + ] + ) # make 10 requests on the same connection, none should produce a status code # reported by erki@example.ee @@ -128,3 +164,13 @@ def test_h2_101_11(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_post_process_client_hello:.*', + r'.*SSL Library Error:.*:SSL routines::no shared cipher.*' + ] + ) diff --git a/test/modules/http2/test_102_require.py b/test/modules/http2/test_102_require.py index b7e4eaef6ed..4b0cad56a24 100644 --- a/test/modules/http2/test_102_require.py +++ b/test/modules/http2/test_102_require.py @@ -39,3 +39,9 @@ def test_h2_102_02(self, env): assert 0 == r.exit_code assert r.response assert 403 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01630" # client denied by server configuration + ] + ) diff --git a/test/modules/http2/test_105_timeout.py b/test/modules/http2/test_105_timeout.py index f7d3859cafb..22160b45853 100644 --- a/test/modules/http2/test_105_timeout.py +++ b/test/modules/http2/test_105_timeout.py @@ -42,6 +42,13 @@ def test_h2_105_01(self, env): except Exception as ex: print(f"as expected: {ex}") sock.close() + # + time.sleep(1) # let the log flush + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10373" # SSL handshake was not completed + ] + ) # Check that mod_reqtimeout handshake setting takes effect def test_h2_105_02(self, env): @@ -77,6 +84,13 @@ def test_h2_105_02(self, env): except Exception as ex: print(f"as expected: {ex}") sock.close() + # + time.sleep(1) # let the log flush + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10373" # SSL handshake was not completed + ] + ) # Check that mod_reqtimeout handshake setting do no longer apply to handshaked # connections. See . diff --git a/test/modules/http2/test_106_shutdown.py b/test/modules/http2/test_106_shutdown.py index 83e143cef58..fab881bcac7 100644 --- a/test/modules/http2/test_106_shutdown.py +++ b/test/modules/http2/test_106_shutdown.py @@ -72,4 +72,10 @@ def test_h2_106_02(self, env): else: assert r.exit_code == 0, f"failed on {i}. request: {r.stdout} {r.stderr}" assert r.response["status"] == 200 - assert "HTTP/2" == r.response["protocol"] \ No newline at end of file + assert "HTTP/2" == r.response["protocol"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH03490" # scoreboard is full, not at MaxRequestWorkers + ] + ) \ No newline at end of file diff --git a/test/modules/http2/test_200_header_invalid.py b/test/modules/http2/test_200_header_invalid.py index fe944878405..a68aaa77e09 100644 --- a/test/modules/http2/test_200_header_invalid.py +++ b/test/modules/http2/test_200_header_invalid.py @@ -28,6 +28,15 @@ def test_h2_200_01(self, env): assert 500 == r.response["status"], f'unexpected status for char 0x{x:02}' else: assert 0 != r.exit_code, f'unexpected exit code for char 0x{x:02}' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02429" # Response header name contains invalid characters + ], + matches = [ + r'.*malformed header from script \'hecho.py\': Bad header: x.*' + ] + ) # let the hecho.py CGI echo chars < 0x20 in field value # for almost all such characters, the stream returns a 500 @@ -46,6 +55,12 @@ def test_h2_200_02(self, env): assert 500 == r.response["status"], f'unexpected status for char 0x{x:02}' else: assert 0 != r.exit_code, "unexpected exit code for char 0x%02x" % x + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02430" # Response header value contains invalid characters + ] + ) # let the hecho.py CGI echo 0x10 and 0x7f in field name and value def test_h2_200_03(self, env): @@ -63,6 +78,13 @@ def test_h2_200_03(self, env): assert 500 == r.response["status"], f"unexpected exit code for char 0x{h:02}" else: assert 0 != r.exit_code + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02429", # Response header name contains invalid characters + "AH02430" # Response header value contains invalid characters + ] + ) # test header field lengths check, LimitRequestLine (default 8190) def test_h2_200_10(self, env): diff --git a/test/modules/http2/test_203_rfc9113.py b/test/modules/http2/test_203_rfc9113.py index 9fc8f3b2242..1fe3e131595 100644 --- a/test/modules/http2/test_203_rfc9113.py +++ b/test/modules/http2/test_203_rfc9113.py @@ -1,4 +1,5 @@ import pytest +from typing import List, Optional from pyhttpd.env import HttpdTestEnv from .env import H2Conf @@ -22,17 +23,17 @@ def test_h2_203_01_ws_ignore(self, env): assert r.response["status"] == 200, f'curl output: {r.stdout}' # response header are also handled, but we strip ws before sending - @pytest.mark.parametrize(["hvalue", "expvalue", "status"], [ - ['"123"', '123', 200], - ['"123 "', '123', 200], # trailing space stripped - ['"123\t"', '123', 200], # trailing tab stripped - ['" 123"', '123', 200], # leading space is stripped - ['" 123"', '123', 200], # leading spaces are stripped - ['"\t123"', '123', 200], # leading tab is stripped - ['"expr=%{unescape:123%0A 123}"', '', 500], # illegal char - ['" \t "', '', 200], # just ws + @pytest.mark.parametrize(["hvalue", "expvalue", "status", "lognos"], [ + ['"123"', '123', 200, None], + ['"123 "', '123', 200, None], # trailing space stripped + ['"123\t"', '123', 200, None], # trailing tab stripped + ['" 123"', '123', 200, None], # leading space is stripped + ['" 123"', '123', 200, None], # leading spaces are stripped + ['"\t123"', '123', 200, None], # leading tab is stripped + ['"expr=%{unescape:123%0A 123}"', '', 500, ["AH02430"]], # illegal char + ['" \t "', '', 200, None], # just ws ]) - def test_h2_203_02(self, env, hvalue, expvalue, status): + def test_h2_203_02(self, env, hvalue, expvalue, status, lognos: Optional[List[str]]): hname = 'ap-test-007' conf = H2Conf(env, extras={ f'test1.{env.http_tld}': [ @@ -53,4 +54,7 @@ def test_h2_203_02(self, env, hvalue, expvalue, status): assert r.response["status"] == status if int(status) < 400: assert r.response["header"][hname] == expvalue + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) diff --git a/test/modules/http2/test_500_proxy.py b/test/modules/http2/test_500_proxy.py index 88a8ece3f6e..87e523c4a21 100644 --- a/test/modules/http2/test_500_proxy.py +++ b/test/modules/http2/test_500_proxy.py @@ -149,9 +149,21 @@ def test_h2_500_31(self, env, repeat): url = env.mkurl("https", "cgi", "/proxy/h2test/error?body_error=timeout") r = env.curl_get(url) assert r.exit_code != 0, r + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01110" # Network error reading response + ] + ) # produce an error, fail to generate an error bucket def test_h2_500_32(self, env, repeat): url = env.mkurl("https", "cgi", "/proxy/h2test/error?body_error=timeout&error_bucket=0") r = env.curl_get(url) assert r.exit_code != 0, r + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01110" # Network error reading response + ] + ) diff --git a/test/modules/http2/test_800_websockets.py b/test/modules/http2/test_800_websockets.py index 97e73737353..2e3d03a0e57 100644 --- a/test/modules/http2/test_800_websockets.py +++ b/test/modules/http2/test_800_websockets.py @@ -154,7 +154,6 @@ def test_h2_800_01_fail_proto(self, env: H2TestEnv, ws_server): r, infos, frames = ws_run(env, path='/ws/echo/', scenario='fail-proto') assert r.exit_code == 0, f'{r}' assert infos == ['[1] :status: 501', '[1] EOF'], f'{r}' - env.httpd_error_log.ignore_recent() # a correct CONNECT, send CLOSE, expect CLOSE, basic success def test_h2_800_02_ws_empty(self, env: H2TestEnv, ws_server): diff --git a/test/modules/md/conftest.py b/test/modules/md/conftest.py index 04165a2dfcd..192cd31a80b 100755 --- a/test/modules/md/conftest.py +++ b/test/modules/md/conftest.py @@ -1,6 +1,5 @@ import logging import os -import re import sys import pytest @@ -37,44 +36,11 @@ def env(pytestconfig) -> MDTestEnv: @pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - # we'd like to check the httpd error logs after the test suite has - # run to catch anything unusual. For this, we setup the ignore list - # of errors and warnings that we do expect. - env.httpd_error_log.set_ignored_lognos([ - 'AH10040', # mod_md, setup complain - 'AH10045', # mod_md complains that there is no vhost for an MDomain - 'AH10056', # mod_md, invalid params - 'AH10105', # mod_md does not find a vhost with SSL enabled for an MDomain - 'AH10085', # mod_ssl complains about fallback certificates - 'AH01909', # mod_ssl, cert alt name complains - 'AH10170', # mod_md, wrong config, tested - 'AH10171', # mod_md, wrong config, tested - 'AH10373', # SSL errors on uncompleted handshakes - 'AH10398', # test on global store lock +def _md_package_scope(env): + env.httpd_error_log.add_ignored_lognos([ + "AH10085" # There are no SSL certificates configured and no other module contributed any ]) - env.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*urn:ietf:params:acme:error:.*'), - re.compile(r'.*None of the ACME challenge methods configured for this domain are suitable.*'), - re.compile(r'.*problem\[(challenge-mismatch|challenge-setup-failure|apache:eab-hmac-invalid)].*'), - re.compile(r'.*CA considers answer to challenge invalid.].*'), - re.compile(r'.*problem\[urn:org:apache:httpd:log:AH\d+:].*'), - re.compile(r'.*Unsuccessful in contacting ACME server at :*'), - re.compile(r'.*test-md-720-002-\S+.org: dns-01 setup command failed .*'), - re.compile(r'.*AH\d*: unable to obtain global registry lock, .*'), - ]) - if env.lacks_ocsp(): - env.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*certificate with serial \S+ has no OCSP responder URL.*'), - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - @pytest.fixture(scope="package") def acme(env): diff --git a/test/modules/md/test_300_conf_validate.py b/test/modules/md/test_300_conf_validate.py index 85371ba227b..f348f5f1789 100644 --- a/test/modules/md/test_300_conf_validate.py +++ b/test/modules/md/test_300_conf_validate.py @@ -24,6 +24,12 @@ def test_md_300_001(self, env): MDomain not-forbidden.org www.not-forbidden.org mail.not-forbidden.org """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomain definitions, non-overlapping def test_md_300_002(self, env): @@ -32,6 +38,12 @@ def test_md_300_002(self, env): MDomain example2.org www.example2.org mail.example2.org """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomain definitions, exactly the same def test_md_300_003(self, env): @@ -41,6 +53,12 @@ def test_md_300_003(self, env): MDomain not-forbidden.org www.not-forbidden.org mail.not-forbidden.org test3.not-forbidden.org """).install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10038" # two Managed Domains have an overlap in domain + ] + ) # test case: two MDomain definitions, overlapping def test_md_300_004(self, env): @@ -50,6 +68,12 @@ def test_md_300_004(self, env): MDomain example2.org test3.not-forbidden.org www.example2.org mail.example2.org """).install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10038" # two Managed Domains have an overlap in domain + ] + ) # test case: two MDomains, one inside a virtual host def test_md_300_005(self, env): @@ -60,6 +84,12 @@ def test_md_300_005(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, one correct vhost name def test_md_300_006(self, env): @@ -71,6 +101,12 @@ def test_md_300_006(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, two correct vhost names def test_md_300_007(self, env): @@ -85,6 +121,12 @@ def test_md_300_007(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, overlapping vhosts def test_md_300_008(self, env): @@ -102,6 +144,12 @@ def test_md_300_008(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: vhosts with overlapping MDs def test_md_300_009(self, env): @@ -118,7 +166,12 @@ def test_md_300_009(self, env): conf.install() assert env.apache_fail() == 0 env.apache_stop() - env.httpd_error_log.ignore_recent() + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10238" # 2 MDs match Virtualhost + ] + ) # test case: MDomain, vhost with matching ServerAlias def test_md_300_010(self, env): @@ -146,6 +199,9 @@ def test_md_300_011a(self, env): conf.install() assert env.apache_fail() == 0 env.apache_stop() + env.httpd_error_log.ignore_recent([ + "AH10040" # A requested MD certificate will not match ServerName + ]) # test case: MDomain, misses one ServerAlias, but auto add enabled def test_md_300_011b(self, env): @@ -171,6 +227,12 @@ def test_md_300_012(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: one md covers two vhosts def test_md_300_013(self, env): @@ -261,7 +323,6 @@ def test_md_300_020(self, env, line, exp_err_msg): MDConf(env, text=line).install() assert env.apache_fail() == 0, "Server accepted test config {}".format(line) assert exp_err_msg in env.apachectl_stderr - env.httpd_error_log.ignore_recent() # test case: alt-names incomplete detection, github isse #68 def test_md_300_021(self, env): @@ -294,6 +355,12 @@ def test_md_300_022(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10105" # MD secret.com does not match any VirtualHost with 'SSLEngine on' + ] + ) # test case: use MDRequireHttps not in 0 assert md['renewal']['last']['status-description'] == 'Connection refused' assert 'account' not in md['ca'] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) # Specify a valid http proxy def test_md_702_008a(self, env): @@ -335,6 +359,16 @@ def test_md_702_010(self, env): assert env.apache_restart() == 0 env.check_md(domains) assert env.await_completion([domain]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) def test_md_702_011(self, env): domain = self.test_domain @@ -364,6 +398,16 @@ def test_md_702_011(self, env): assert env.apache_restart() == 0 env.check_md(domains) assert env.await_completion([domain]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) # test case: one MD with several dns names. sign up. remove the *first* name # in the MD. restart. should find and keep the existing MD. @@ -648,6 +692,16 @@ def test_md_702_051(self, env): conf.install() assert env.apache_restart() == 0 assert env.await_error(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) # Make a setup using the base server without http:, but with acme-tls/1, should work. def test_md_702_052(self, env): diff --git a/test/modules/md/test_720_wildcard.py b/test/modules/md/test_720_wildcard.py index 23b311c3a47..916c47a5d85 100644 --- a/test/modules/md/test_720_wildcard.py +++ b/test/modules/md/test_720_wildcard.py @@ -44,6 +44,15 @@ def test_md_720_001(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-mismatch' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-mismatch\].*' + ] + ) # test case: a wildcard certificate with ACMEv2, only dns-01 configured, invalid command path def test_md_720_002(self, env): @@ -67,6 +76,16 @@ def test_md_720_002(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-setup-failure' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-setup-failure\].*', + r'.*setup command failed to execute.*' + ] + ) # variation, invalid cmd path, other challenges still get certificate for non-wildcard def test_md_720_002b(self, env): @@ -113,6 +132,15 @@ def test_md_720_003(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-setup-failure' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test case: a wildcard name certificate with ACMEv2, only dns-01 configured def test_md_720_004(self, env): diff --git a/test/modules/md/test_730_static.py b/test/modules/md/test_730_static.py index f7f7b4b2cfe..891ae620bb8 100644 --- a/test/modules/md/test_730_static.py +++ b/test/modules/md/test_730_static.py @@ -115,3 +115,10 @@ def test_md_730_003(self, env): conf.add_vhost(domain) conf.install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10170", # Managed Domain needs one MDCertificateKeyFile for each MDCertificateFile + "AH10171" # Managed Domain has MDCertificateKeyFile(s) but no MDCertificateFile + ] + ) diff --git a/test/modules/md/test_740_acme_errors.py b/test/modules/md/test_740_acme_errors.py index 670c9ab831a..364aaca6c8d 100644 --- a/test/modules/md/test_740_acme_errors.py +++ b/test/modules/md/test_740_acme_errors.py @@ -46,6 +46,15 @@ def test_md_740_000(self, env): assert md['renewal']['last']['detail'] == ( "Error creating new order :: Cannot issue for " "\"%s\": Domain name contains an invalid character" % domains[1]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Order included DNS identifier with a value containing an illegal character + ], + matches = [ + r'.*urn:ietf:params:acme:error:malformed.*' + ] + ) # test case: MD with 3 names, 2 invalid # @@ -70,3 +79,12 @@ def test_md_740_001(self, env): "Error creating new order :: Cannot issue for") assert md['renewal']['last']['subproblems'] assert len(md['renewal']['last']['subproblems']) == 2 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Order included DNS identifier with a value containing an illegal character + ], + matches = [ + r'.*urn:ietf:params:acme:error:malformed.*' + ] + ) diff --git a/test/modules/md/test_741_setup_errors.py b/test/modules/md/test_741_setup_errors.py index 49b4e788c06..9ad79f0b1e9 100644 --- a/test/modules/md/test_741_setup_errors.py +++ b/test/modules/md/test_741_setup_errors.py @@ -46,3 +46,13 @@ def test_md_741_001(self, env): md = env.await_error(domain, errors=2, timeout=10) assert md assert md['renewal']['errors'] > 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # CA considers answer to challenge invalid + ], + matches = [ + r'.*The key authorization file from the server did not match this challenge.*', + r'.*CA considers answer to challenge invalid.*' + ] + ) diff --git a/test/modules/md/test_750_eab.py b/test/modules/md/test_750_eab.py index af1be95d05a..7d81917829e 100644 --- a/test/modules/md/test_750_eab.py +++ b/test/modules/md/test_750_eab.py @@ -37,6 +37,15 @@ def test_md_750_001(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_002(self, env): # md with known EAB KID and non base64 hmac key configured @@ -51,6 +60,15 @@ def test_md_750_002(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'apache:eab-hmac-invalid' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # external account binding HMAC value is not valid base64 + ], + matches = [ + r'.*problem\[apache:eab-hmac-invalid\].*' + ] + ) def test_md_750_003(self, env): # md with empty EAB KID configured @@ -65,6 +83,15 @@ def test_md_750_003(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_004(self, env): # md with unknown EAB KID configured @@ -79,6 +106,15 @@ def test_md_750_004(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_005(self, env): # md with known EAB KID but wrong HMAC configured @@ -93,6 +129,15 @@ def test_md_750_005(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # external account binding JWS verification error: square/go-jose: error in cryptographic primitive + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_010(self, env): # md with correct EAB configured @@ -125,6 +170,15 @@ def test_md_750_011(self, env): md = env.await_error(domain_b) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_012(self, env): # first one md without EAB, then one with @@ -144,6 +198,15 @@ def test_md_750_012(self, env): md = env.await_error(domain_a) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_013(self, env): # 2 mds with the same EAB, should one create a single account @@ -215,6 +278,15 @@ def test_md_750_015(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_016(self, env): # md with correct EAB, get cert, change to invalid EAB @@ -241,6 +313,15 @@ def test_md_750_016(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_017(self, env): # md without EAB explicitly set to none @@ -257,6 +338,15 @@ def test_md_750_017(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_018(self, env): # md with EAB file that does not exist diff --git a/test/modules/md/test_780_tailscale.py b/test/modules/md/test_780_tailscale.py index 84a266b2eb7..27a2df474aa 100644 --- a/test/modules/md/test_780_tailscale.py +++ b/test/modules/md/test_780_tailscale.py @@ -140,6 +140,12 @@ def test_md_780_001(self, env): assert md['renewal']['last']['status-description'] == 'No such file or directory' assert md['renewal']['last']['detail'] == \ f"tailscale socket not available, may not be up: {socket_path}" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # retrieving certificate from tailscale + ] + ) # create a MD using `tailscale` as protocol, path to faker, should succeed def test_md_780_002(self, env): @@ -184,3 +190,9 @@ def test_md_780_003(self, env): assert md['renewal']['errors'] > 0 assert md['renewal']['last']['status-description'] == 'No such file or directory' assert md['renewal']['last']['detail'] == "retrieving certificate from tailscale" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # retrieving certificate from tailscale + ] + ) diff --git a/test/modules/md/test_790_failover.py b/test/modules/md/test_790_failover.py index a93991233d3..696161fd4fd 100644 --- a/test/modules/md/test_790_failover.py +++ b/test/modules/md/test_790_failover.py @@ -63,6 +63,15 @@ def test_md_790_002(self, env): assert env.apache_restart() == 0 assert env.await_completion([domain]) env.check_md_complete(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) # set 3 ACME certificata authority, invalid + invalid + valid def test_md_790_003(self, env): @@ -85,3 +94,12 @@ def test_md_790_003(self, env): assert env.apache_restart() == 0 assert env.await_completion([domain]) env.check_md_complete(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) diff --git a/test/modules/md/test_900_notify.py b/test/modules/md/test_900_notify.py index 30e0742036c..9d18da54114 100644 --- a/test/modules/md/test_900_notify.py +++ b/test/modules/md/test_900_notify.py @@ -49,6 +49,12 @@ def test_md_900_001(self, env): assert env.await_error(self.domain) stat = env.get_md_status(self.domain) assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10108:" + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*urn:org:apache:httpd:log:AH10108:.*' + ] + ) # test: valid notify cmd that fails, check error def test_md_900_002(self, env): @@ -61,6 +67,14 @@ def test_md_900_002(self, env): assert env.await_error(self.domain) stat = env.get_md_status(self.domain) assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10108:" + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*urn:org:apache:httpd:log:AH10108:.*', + r'.*urn:org:apache:httpd:log:AH10109:.*' + r'.*problem\[challenge-setup-failure\].*', + ] + ) # test: valid notify that logs to file def test_md_900_010(self, env): diff --git a/test/modules/md/test_901_message.py b/test/modules/md/test_901_message.py index 8d03bfd6a31..b18cfd38d44 100644 --- a/test/modules/md/test_901_message.py +++ b/test/modules/md/test_901_message.py @@ -46,6 +46,16 @@ def test_md_901_001(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test: signup with configured message cmd that is valid but returns != 0 def test_md_901_002(self, env): @@ -63,6 +73,16 @@ def test_md_901_002(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test: signup with working message cmd and see that it logs the right things def test_md_901_003(self, env): @@ -247,7 +267,6 @@ def test_md_901_030(self, env): assert job["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" break time.sleep(0.1) - env.httpd_error_log.ignore_recent() # reconfigure to a working notification command and restart conf = MDConf(env) @@ -294,4 +313,13 @@ def test_md_901_040(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "challenge-setup-failure" - + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) diff --git a/test/modules/md/test_920_status.py b/test/modules/md/test_920_status.py index c89ce6d8d70..6ad708728c7 100644 --- a/test/modules/md/test_920_status.py +++ b/test/modules/md/test_920_status.py @@ -243,3 +243,9 @@ def test_md_920_020(self, env): assert ktype in stat['cert'] if env.acme_server == 'boulder': assert 'ocsp' in stat['cert'][ktype] + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*certificate with serial \w+ has no OCSP responder URL.*' + ] + ) diff --git a/test/modules/proxy/conftest.py b/test/modules/proxy/conftest.py index 23c5f14201f..7e6f4e7b09d 100644 --- a/test/modules/proxy/conftest.py +++ b/test/modules/proxy/conftest.py @@ -29,23 +29,3 @@ def env(pytestconfig) -> ProxyTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - # we'd like to check the httpd error logs after the test suite has - # run to catch anything unusual. For this, we setup the ignore list - # of errors and warnings that we do expect. - env.httpd_error_log.set_ignored_lognos([ - 'AH01144', # No protocol handler was valid for the URL - ]) - - env.httpd_error_log.add_ignored_patterns([ - #re.compile(r'.*urn:ietf:params:acme:error:.*'), - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) diff --git a/test/modules/proxy/env.py b/test/modules/proxy/env.py index 9ed635cd5fb..098d4d49485 100644 --- a/test/modules/proxy/env.py +++ b/test/modules/proxy/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any diff --git a/test/modules/proxy/test_02_unix.py b/test/modules/proxy/test_02_unix.py index 7f3d4d55b2b..0c39bc9c12c 100644 --- a/test/modules/proxy/test_02_unix.py +++ b/test/modules/proxy/test_02_unix.py @@ -153,6 +153,12 @@ def test_proxy_02_003(self, env, via, exp_status): r2 = self.parse_response(rlines) assert r2.response assert r2.response['status'] == exp_status + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01144" # No protocol handler was valid for the URL + ] + ) def parse_response(self, lines) -> ExecResult: exp_body = False diff --git a/test/modules/tls/conftest.py b/test/modules/tls/conftest.py index cde4be60714..c7cb85877d5 100644 --- a/test/modules/tls/conftest.py +++ b/test/modules/tls/conftest.py @@ -31,9 +31,3 @@ def env(pytestconfig) -> TlsTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 diff --git a/test/modules/tls/test_03_sni.py b/test/modules/tls/test_03_sni.py index cf421c0fe81..cbd142afbc9 100644 --- a/test/modules/tls/test_03_sni.py +++ b/test/modules/tls/test_03_sni.py @@ -34,6 +34,12 @@ def test_tls_03_sni_unknown(self, env): domain_unknown = "unknown.test" r = env.tls_get(domain_unknown, "/index.json") assert r.exit_code != 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10353" # cannot decrypt peer's message + ] + ) def test_tls_03_sni_request_other_same_config(self, env): # do we see the first vhost response for another domain with different certs? @@ -44,6 +50,12 @@ def test_tls_03_sni_request_other_same_config(self, env): assert r.exit_code == 0 assert r.json is None assert r.response['status'] == 421 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10345" # Connection host selected via SNI and request have incompatible TLS configurations + ] + ) def test_tls_03_sni_request_other_other_honor(self, env): # do we see the first vhost response for an unknown domain? @@ -60,6 +72,12 @@ def test_tls_03_sni_request_other_other_honor(self, env): # request denied assert r.exit_code == 0 assert r.json is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10345" # Connection host selected via SNI and request have incompatible TLS configurations + ] + ) @pytest.mark.skip('openssl behaviour changed on ventura, unreliable') def test_tls_03_sni_bad_hostname(self, env): diff --git a/test/modules/tls/test_06_ciphers.py b/test/modules/tls/test_06_ciphers.py index 2e60bdd7563..6f515e4d777 100644 --- a/test/modules/tls/test_06_ciphers.py +++ b/test/modules/tls/test_06_ciphers.py @@ -176,16 +176,18 @@ def test_tls_06_ciphers_pref_unknown(self, env): def test_tls_06_ciphers_pref_unsupported(self, env): # a warning on preferring a known, but not supported cipher - env.httpd_error_log.ignore_recent() conf = TlsTestConf(env=env, extras={ env.domain_b: "TLSCiphersPrefer TLS_NULL_WITH_NULL_NULL" }) conf.add_tls_vhosts(domains=[env.domain_a, env.domain_b]) conf.install() assert env.apache_restart() == 0 - (errors, warnings) = env.httpd_error_log.get_recent_count() - assert errors == 0 - assert warnings == 2 # once on dry run, once on start + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10319" # Server has TLSCiphersPrefer configured that are not supported by rustls + ] + ) def test_tls_06_ciphers_supp_unknown(self, env): conf = TlsTestConf(env=env, extras={ @@ -197,13 +199,9 @@ def test_tls_06_ciphers_supp_unknown(self, env): def test_tls_06_ciphers_supp_unsupported(self, env): # no warnings on suppressing known, but not supported ciphers - env.httpd_error_log.ignore_recent() conf = TlsTestConf(env=env, extras={ env.domain_b: "TLSCiphersSuppress TLS_NULL_WITH_NULL_NULL" }) conf.add_tls_vhosts(domains=[env.domain_a, env.domain_b]) conf.install() assert env.apache_restart() == 0 - (errors, warnings) = env.httpd_error_log.get_recent_count() - assert errors == 0 - assert warnings == 0 diff --git a/test/modules/tls/test_14_proxy_ssl.py b/test/modules/tls/test_14_proxy_ssl.py index 79b2fb4b041..3118b4dda1e 100644 --- a/test/modules/tls/test_14_proxy_ssl.py +++ b/test/modules/tls/test_14_proxy_ssl.py @@ -48,6 +48,13 @@ def test_tls_14_proxy_ssl_get_local(self, env): # does not work, since SSLProxy* not configured data = env.tls_get_json(env.domain_b, "/proxy-local/index.json") assert data is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01961", # failed to enable ssl support [Hint: if using mod_ssl, see SSLProxyEngine] + "AH00961" # failed to enable ssl support (mod_proxy) + ] + ) def test_tls_14_proxy_ssl_h2_get(self, env): r = env.tls_get(env.domain_b, "/proxy-h2-ssl/index.json") diff --git a/test/modules/tls/test_15_proxy_tls.py b/test/modules/tls/test_15_proxy_tls.py index f2f670d7e99..ed881a034dc 100644 --- a/test/modules/tls/test_15_proxy_tls.py +++ b/test/modules/tls/test_15_proxy_tls.py @@ -1,4 +1,3 @@ -import re from datetime import timedelta import pytest @@ -53,6 +52,13 @@ def test_tls_15_proxy_tls_get_local(self, env): # does not work, since SSLProxy* not configured data = env.tls_get_json(env.domain_b, "/proxy-local/index.json") assert data is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01961", # failed to enable ssl support [Hint: if using mod_ssl, see SSLProxyEngine] + "AH00961" # failed to enable ssl support (mod_proxy) + ] + ) def test_tls_15_proxy_tls_h2_get(self, env): r = env.tls_get(env.domain_b, "/proxy-h2-tls/index.json") diff --git a/test/pyhttpd/env.py b/test/pyhttpd/env.py index f8d27d04cd8..5a2525c92da 100644 --- a/test/pyhttpd/env.py +++ b/test/pyhttpd/env.py @@ -324,6 +324,12 @@ def setup_httpd(self, setup: HttpdTestSetup = None): for name in self._httpd_log_modules: self._log_interesting += f" {name}:{log_level}" + def check_error_log(self): + errors, warnings = self._error_log.get_missed() + assert (len(errors), len(warnings)) == (0, 0),\ + f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ + "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) + @property def curl(self) -> str: return self._curl @@ -558,6 +564,7 @@ def mkurl(self, scheme, hostname, path='/'): return f"{scheme}://{hostname}.{self.http_tld}:{port}{path}" def install_test_conf(self, lines: List[str]): + self.apache_stop() with open(self._test_conf, 'w') as fd: fd.write('\n'.join(self._httpd_base_conf)) fd.write('\n') diff --git a/test/pyhttpd/log.py b/test/pyhttpd/log.py index dff7623b246..17b0502e9de 100644 --- a/test/pyhttpd/log.py +++ b/test/pyhttpd/log.py @@ -8,33 +8,32 @@ class HttpdErrorLog: """Checking the httpd error log for errors and warnings, including - limiting checks from a last known position forward. + limiting checks from a recent known position forward. """ - RE_ERRLOG_ERROR = re.compile(r'.*\[(?P[^:]+):error].*') - RE_ERRLOG_WARN = re.compile(r'.*\[(?P[^:]+):warn].*') - RE_APLOGNO = re.compile(r'.*\[(?P[^:]+):(error|warn)].* (?PAH\d+): .+') - RE_SSL_LIB_ERR = re.compile(r'.*\[ssl:error].* SSL Library Error: error:(?P\S+):.+') + RE_ERRLOG_WARN = re.compile(r'.*\[[^:]+:warn].*') + RE_ERRLOG_ERROR = re.compile(r'.*\[[^:]+:error].*') + RE_APLOGNO = re.compile(r'.*\[[^:]+:(error|warn)].* (?PAH\d+): .+') def __init__(self, path: str): self._path = path - self._ignored_modules = [] + self._ignored_matches = [] self._ignored_lognos = set() - self._ignored_patterns = [] # remember the file position we started with self._start_pos = 0 if os.path.isfile(self._path): with open(self._path) as fd: self._start_pos = fd.seek(0, SEEK_END) - self._last_pos = self._start_pos - self._last_errors = [] - self._last_warnings = [] - self._observed_erros = set() - self._observed_warnings = set() + self._recent_pos = self._start_pos + self._recent_errors = [] + self._recent_warnings = [] + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() def __repr__(self): - return f"HttpdErrorLog[{self._path}, errors: {' '.join(self._last_errors)}, " \ - f"warnings: {' '.join(self._last_warnings)}]" + return f"HttpdErrorLog[{self._path}, errors: {' '.join(self._recent_errors)}, " \ + f"warnings: {' '.join(self._recent_warnings)}]" @property def path(self) -> str: @@ -42,118 +41,108 @@ def path(self) -> str: def clear_log(self): if os.path.isfile(self.path): - os.remove(self.path) - self._start_pos = 0 - self._last_pos = self._start_pos - self._last_errors = [] - self._last_warnings = [] - self._observed_erros = set() - self._observed_warnings = set() + os.truncate(self.path, 0) + self._start_pos = self._recent_pos = 0 + self._recent_errors = [] + self._recent_warnings = [] + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() + + def _lookup_matches(self, line: str, matches: List[str]) -> bool: + for m in matches: + if re.match(m, line): + return True + return False + + def _lookup_lognos(self, line: str, lognos: set) -> bool: + if len(lognos) > 0: + m = self.RE_APLOGNO.match(line) + if m and m.group('aplogno') in lognos: + return True + return False - def set_ignored_modules(self, modules: List[str]): - self._ignored_modules = modules.copy() if modules else [] + def clear_ignored_matches(self): + self._ignored_matches = [] - def set_ignored_lognos(self, lognos: List[str]): - if lognos: - for l in lognos: - self._ignored_lognos.add(l) + def add_ignored_matches(self, matches: List[str]): + for m in matches: + self._ignored_matches.append(re.compile(m)) - def add_ignored_patterns(self, patterns: List[Any]): - self._ignored_patterns.extend(patterns) + def clear_ignored_lognos(self): + self._ignored_lognos = set() + + def add_ignored_lognos(self, lognos: List[str]): + for l in lognos: + self._ignored_lognos.add(l) def _is_ignored(self, line: str) -> bool: - for p in self._ignored_patterns: - if p.match(line): - return True - m = self.RE_APLOGNO.match(line) - if m and m.group('aplogno') in self._ignored_lognos: + if self._lookup_matches(line, self._ignored_matches): + return True + if self._lookup_lognos(line, self._ignored_lognos): return True return False - def get_recent(self, advance=True) -> Tuple[List[str], List[str]]: - """Collect error and warning from the log since the last remembered position - :param advance: advance the position to the end of the log afterwards - :return: list of error and list of warnings as tuple - """ - self._last_errors = [] - self._last_warnings = [] + def ignore_recent(self, lognos: List[str] = [], matches: List[str] = []): + """After a test case triggered errors/warnings on purpose, add + those to our 'caught' list so the do not get reported as 'missed'. + """ + self._recent_errors = [] + self._recent_warnings = [] if os.path.isfile(self._path): with open(self._path) as fd: - fd.seek(self._last_pos, os.SEEK_SET) + fd.seek(self._recent_pos, os.SEEK_SET) + lognos_set = set(lognos) for line in fd: if self._is_ignored(line): continue - m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules: - self._last_errors.append(line) + if self._lookup_matches(line, matches): + self._caught_matches.add(line) continue m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules: - self._last_warnings.append(line) - continue - if advance: - self._last_pos = fd.tell() - self._observed_erros.update(set(self._last_errors)) - self._observed_warnings.update(set(self._last_warnings)) - return self._last_errors, self._last_warnings - - def get_recent_count(self, advance=True): - errors, warnings = self.get_recent(advance=advance) - return len(errors), len(warnings) - - def ignore_recent(self): - """After a test case triggered errors/warnings on purpose, add - those to our 'observed' list so the do not get reported as 'missed'. - """ - self._last_errors = [] - self._last_warnings = [] - if os.path.isfile(self._path): - with open(self._path) as fd: - fd.seek(self._last_pos, os.SEEK_SET) - for line in fd: - if self._is_ignored(line): + if m and self._lookup_lognos(line, lognos_set): + self._caught_warnings.add(line) continue m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules: - self._observed_erros.add(line) + if m and self._lookup_lognos(line, lognos_set): + self._caught_errors.add(line) continue - m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules: - self._observed_warnings.add(line) - continue - self._last_pos = fd.tell() + self._recent_pos = fd.tell() def get_missed(self) -> Tuple[List[str], List[str]]: errors = [] warnings = [] + self._recent_errors = [] + self._recent_warnings = [] if os.path.isfile(self._path): with open(self._path) as fd: fd.seek(self._start_pos, os.SEEK_SET) for line in fd: if self._is_ignored(line): continue + if line in self._caught_matches: + continue + m = self.RE_ERRLOG_WARN.match(line) + if m and line not in self._caught_warnings: + warnings.append(line) + continue m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules \ - and line not in self._observed_erros: + if m and line not in self._caught_errors: errors.append(line) continue - m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules \ - and line not in self._observed_warnings: - warnings.append(line) - continue + self._start_pos = self._recent_pos = fd.tell() + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() return errors, warnings - def scan_recent(self, pattern: re, timeout=10): + def scan_recent(self, pattern: re.Pattern, timeout=10): if not os.path.isfile(self.path): return False with open(self.path) as fd: end = datetime.now() + timedelta(seconds=timeout) while True: - fd.seek(self._last_pos, os.SEEK_SET) + fd.seek(self._recent_pos, os.SEEK_SET) for line in fd: if pattern.match(line): return True