diff --git a/bin/tests/system/checkds/tests_checkds.py b/bin/tests/system/checkds/tests_checkds.py index 01c34de132..b6fcaa15d8 100755 --- a/bin/tests/system/checkds/tests_checkds.py +++ b/bin/tests/system/checkds/tests_checkds.py @@ -356,12 +356,15 @@ def test_checkds(servers, params): # Wait until the provided zone is signed and then verify its DNSSEC data. zone_check(servers["ns9"], params.zone) - # Wait until all the expected log lines are found in the log file for the - # provided server. + # Wait up to 10 seconds until all the expected log lines are found in the + # log file for the provided server. + time_remaining = 10 for log_string in params.logs_to_wait_for: - with servers["ns9"].watch_log_from_start() as watcher: - line = f"zone {params.zone}/IN (signed): checkds: {log_string}" - watcher.wait_for_line(line) + line = f"zone {params.zone}/IN (signed): checkds: {log_string}" + while line not in servers["ns9"].log: + time_remaining -= 1 + assert time_remaining, f'Timed out waiting for "{log_string}" to be logged' + time.sleep(1) # Check whether key states on the parent server provided match # expectations. diff --git a/bin/tests/system/conftest.py b/bin/tests/system/conftest.py index 692743115c..a1a42770cf 100644 --- a/bin/tests/system/conftest.py +++ b/bin/tests/system/conftest.py @@ -357,6 +357,27 @@ def mlogger(system_test_name): return logging.getLogger(system_test_name) +def _get_marker(node, marker): + try: + # pytest >= 4.x + return node.get_closest_marker(marker) + except AttributeError: + # pytest < 4.x + return node.get_marker(marker) + + +@pytest.fixture(autouse=True) +def wait_for_zones_loaded(request, servers): + """Wait for all zones to be loaded by specified named instances.""" + instances = _get_marker(request.node, "requires_zones_loaded") + if not instances: + return + + for instance in instances.args: + with servers[instance].watch_log_from_start() as watcher: + watcher.wait_for_line("all zones loaded") + + @pytest.fixture def logger(request, system_test_name): """Logging facility specific to a particular test.""" diff --git a/bin/tests/system/isctest/__init__.py b/bin/tests/system/isctest/__init__.py index a55c128007..3ea82a3f45 100644 --- a/bin/tests/system/isctest/__init__.py +++ b/bin/tests/system/isctest/__init__.py @@ -13,4 +13,4 @@ from . import check from . import instance from . import query from . import rndc -from . import watchlog +from . import log diff --git a/bin/tests/system/isctest/instance.py b/bin/tests/system/isctest/instance.py index fdac94c7d2..ede48c095c 100644 --- a/bin/tests/system/isctest/instance.py +++ b/bin/tests/system/isctest/instance.py @@ -18,7 +18,7 @@ import os import re from .rndc import RNDCBinaryExecutor, RNDCException, RNDCExecutor -from .watchlog import WatchLogFromStart, WatchLogFromHere +from .log import LogFile, WatchLogFromStart, WatchLogFromHere class NamedPorts(NamedTuple): @@ -63,7 +63,7 @@ class NamedInstance: """ self.ip = self._identifier_to_ip(identifier) self.ports = ports - self._log_file = os.path.join(identifier, "named.run") + self.log = LogFile(os.path.join(identifier, "named.run")) self._rndc_executor = rndc_executor or RNDCBinaryExecutor() self._rndc_logger = rndc_logger or logging.getLogger() @@ -133,14 +133,14 @@ class NamedInstance: Return an instance of the `WatchLogFromStart` context manager for this `named` instance's log file. """ - return WatchLogFromStart(self._log_file) + return WatchLogFromStart(self.log.path) def watch_log_from_here(self) -> WatchLogFromHere: """ Return an instance of the `WatchLogFromHere` context manager for this `named` instance's log file. """ - return WatchLogFromHere(self._log_file) + return WatchLogFromHere(self.log.path) def reconfigure(self) -> None: """ diff --git a/bin/tests/system/isctest/watchlog.py b/bin/tests/system/isctest/log.py similarity index 91% rename from bin/tests/system/isctest/watchlog.py rename to bin/tests/system/isctest/log.py index 1456c535c9..8a382626c0 100644 --- a/bin/tests/system/isctest/watchlog.py +++ b/bin/tests/system/isctest/log.py @@ -9,7 +9,7 @@ # See the COPYRIGHT file distributed with this work for additional # information regarding copyright ownership. -from typing import Optional, TextIO, Dict, Any, overload, List, Union +from typing import Iterator, Optional, TextIO, Dict, Any, overload, List, Union import abc import os @@ -22,6 +22,40 @@ class WatchLogException(Exception): pass +class LogFile: + """ + Log file wrapper with a path and means to find a string in its contents. + """ + + def __init__(self, path: str): + self.path = path + + @property + def _lines(self) -> Iterator[str]: + with open(self.path, encoding="utf-8") as f: + yield from f + + def __contains__(self, substring: str) -> bool: + """ + Return whether any of the lines in the log contains a given string. + """ + for line in self._lines: + if substring in line: + return True + return False + + def expect(self, msg: str): + """Check the string is present anywhere in the log file.""" + if msg in self: + return + assert False, f"log message not found in log {self.path}: {msg}" + + def prohibit(self, msg: str): + """Check the string is not present in the entire log file.""" + if msg in self: + assert False, f"forbidden message appeared in log {self.path}: {msg}" + + class WatchLog(abc.ABC): """ @@ -193,6 +227,7 @@ class WatchLog(abc.ABC): if not self._fd: raise WatchLogException("No file to watch") leftover = "" + assert timeout, "Do not use this class unless you want to WAIT for something." deadline = time.time() + timeout while time.time() < deadline: for line in self._fd.readlines(): diff --git a/bin/tests/system/pytest.ini b/bin/tests/system/pytest.ini index 1559595852..a8733cefb6 100644 --- a/bin/tests/system/pytest.ini +++ b/bin/tests/system/pytest.ini @@ -18,3 +18,5 @@ log_level = INFO python_files = tests_*.py junit_logging = log junit_log_passing_tests = 0 +markers = + requires_zones_loaded: ensures the test does not start until the specified named instances load all configured zones diff --git a/bin/tests/system/spf/tests.sh b/bin/tests/system/spf/tests.sh deleted file mode 100644 index a74f55904e..0000000000 --- a/bin/tests/system/spf/tests.sh +++ /dev/null @@ -1,46 +0,0 @@ -#!/bin/sh - -# Copyright (C) Internet Systems Consortium, Inc. ("ISC") -# -# SPDX-License-Identifier: MPL-2.0 -# -# This Source Code Form is subject to the terms of the Mozilla Public -# License, v. 2.0. If a copy of the MPL was not distributed with this -# file, you can obtain one at https://mozilla.org/MPL/2.0/. -# -# See the COPYRIGHT file distributed with this work for additional -# information regarding copyright ownership. - -set -e - -. ../conf.sh - -n=1 -status=0 - -# Wait until all zones are loaded before checking SPF related logs -for i in 1 2 3 4 5 6 7 8 9 10; do - grep "all zones loaded" ns1/named.run >/dev/null && break - sleep 1 -done - -echo_i "checking that SPF warnings have been correctly generated ($n)" -ret=0 - -grep "zone spf/IN: loaded serial 0" ns1/named.run >/dev/null || ret=1 -grep "'y.spf' found type SPF" ns1/named.run >/dev/null || ret=1 -grep "'spf' found type SPF" ns1/named.run >/dev/null && ret=1 - -grep "zone warn/IN: loaded serial 0" ns1/named.run >/dev/null || ret=1 -grep "'y.warn' found type SPF" ns1/named.run >/dev/null || ret=1 -grep "'warn' found type SPF" ns1/named.run >/dev/null && ret=1 - -grep "zone nowarn/IN: loaded serial 0" ns1/named.run >/dev/null || ret=1 -grep "'y.nowarn' found type SPF" ns1/named.run >/dev/null && ret=1 -grep "'nowarn' found type SPF" ns1/named.run >/dev/null && ret=1 -n=$((n + 1)) -if [ $ret != 0 ]; then echo_i "failed"; fi -status=$((status + ret)) - -echo_i "exit status: $status" -[ $status -eq 0 ] || exit 1 diff --git a/bin/tests/system/spf/tests_sh_spf.py b/bin/tests/system/spf/tests_sh_spf.py deleted file mode 100644 index 53c623d594..0000000000 --- a/bin/tests/system/spf/tests_sh_spf.py +++ /dev/null @@ -1,14 +0,0 @@ -# Copyright (C) Internet Systems Consortium, Inc. ("ISC") -# -# SPDX-License-Identifier: MPL-2.0 -# -# This Source Code Form is subject to the terms of the Mozilla Public -# License, v. 2.0. If a copy of the MPL was not distributed with this -# file, you can obtain one at https://mozilla.org/MPL/2.0/. -# -# See the COPYRIGHT file distributed with this work for additional -# information regarding copyright ownership. - - -def test_spf(run_tests_sh): - run_tests_sh() diff --git a/bin/tests/system/spf/tests_spf_zones.py b/bin/tests/system/spf/tests_spf_zones.py new file mode 100644 index 0000000000..550704ba51 --- /dev/null +++ b/bin/tests/system/spf/tests_spf_zones.py @@ -0,0 +1,32 @@ +# Copyright (C) Internet Systems Consortium, Inc. ("ISC") +# +# SPDX-License-Identifier: MPL-2.0 +# +# This Source Code Form is subject to the terms of the Mozilla Public +# License, v. 2.0. If a copy of the MPL was not distributed with this +# file, you can obtain one at https://mozilla.org/MPL/2.0/. +# +# See the COPYRIGHT file distributed with this work for additional +# information regarding copyright ownership. + +import pytest + + +@pytest.mark.requires_zones_loaded("ns1") +def test_spf_log(servers): + for msg in ( + "zone spf/IN: 'y.spf' found type SPF record but no SPF TXT record found", + "zone warn/IN: 'y.warn' found type SPF record but no SPF TXT record found", + "zone spf/IN: loaded serial 0", + "zone warn/IN: loaded serial 0", + "zone nowarn/IN: loaded serial 0", + ): + servers["ns1"].log.expect(msg) + + for msg in ( + "zone nowarn/IN: 'y.nowarn' found type SPF record but no SPF TXT record found", + "zone spf/IN: 'spf' found type SPF record but no SPF TXT record found", + "zone warn/IN: 'warn' found type SPF record but no SPF TXT record found", + "zone nowarn/IN: 'nowarn' found type SPF record but no SPF TXT record found", + ): + servers["ns1"].log.prohibit(msg)