From 356883f0e48be59bcb154096cef82cbf3f0dd9d8 Mon Sep 17 00:00:00 2001 From: Hodlinator <172445034+hodlinator@users.noreply.github.com> Date: Tue, 8 Jul 2025 23:14:47 +0200 Subject: [PATCH] qa-tests: Log expected output in debug Helpful when comparing expected/unexpected outputs against each other for working/broken code. Also account for TimeoutExpired.output being None and halt instead of re-raising. --- .../feature_framework_startup_failures.py | 24 ++++++++++++------- 1 file changed, 15 insertions(+), 9 deletions(-) diff --git a/test/functional/feature_framework_startup_failures.py b/test/functional/feature_framework_startup_failures.py index 115b36ada36..ee031e11a5b 100755 --- a/test/functional/feature_framework_startup_failures.py +++ b/test/functional/feature_framework_startup_failures.py @@ -36,22 +36,24 @@ class FeatureFrameworkStartupFailures(BitcoinTestFramework): # Launches a child test process that runs this same file, but instantiates # a child test. Verifies that it raises only the expected exception, once. def _verify_startup_failure(self, test, internal_args, expected_exception): + name = test.__name__ + def format_child_output(output): + return f"\n<{name} OUTPUT BEGIN>\n{output.strip()}\n<{name} OUTPUT END>\n" + # Inherit sys.argv from parent, only overriding tmpdir to a subdirectory # so children don't fail due to colliding with the parent dir. assert self.options.tmpdir, "Framework should always set tmpdir." subdir = md5(expected_exception.encode('utf-8')).hexdigest()[:8] - args = [sys.executable] + sys.argv + [f"--tmpdir={self.options.tmpdir}/{subdir}", f"--internal_test={test.__name__}"] + internal_args + args = [sys.executable] + sys.argv + [f"--tmpdir={self.options.tmpdir}/{subdir}", f"--internal_test={name}"] + internal_args try: output = subprocess.run(args, timeout=60 * self.options.timeout_factor, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True).stdout except subprocess.TimeoutExpired as e: - print("Unexpected child process timeout!\n" - "WARNING: Timeouts like this halt execution of TestNode logic, " - "meaning dangling bitcoind processes are to be expected.\n" - f"\n{e.output.decode("utf-8")}\n", - file=sys.stderr) - raise + sys.exit("Unexpected child process timeout!\n" + "WARNING: Timeouts like this halt execution of TestNode logic, " + "meaning dangling bitcoind processes are to be expected.\n" + + (format_child_output(e.output.decode("utf-8")) if e.output else "")) errors = [] if (n := output.count("Traceback")) != 1: @@ -61,13 +63,17 @@ class FeatureFrameworkStartupFailures(BitcoinTestFramework): if (n := output.count("Test failed. Test logging available at")) != 1: errors.append(f"Found {n}/1 test failure output messages.") - assert not errors, f"Child test didn't contain (only) expected errors:\n{linesep.join(errors)}\n\n{output}\n\n" + assert not errors, (f"Child test did NOT contain (only) expected errors:\n{linesep.join(errors)}\n" + + format_child_output(output)) + + self.log.debug("Child test did contain (only) expected errors:\n" + + format_child_output(output)) def run_test(self): self.log.info("Verifying _verify_startup_failure() functionality (self-check).") assert_raises_message( AssertionError, - ( "Child test didn't contain (only) expected errors:\n" + ( "Child test did NOT contain (only) expected errors:\n" f"Found 0/1 tracebacks - expecting exactly one with no knock-on exceptions.{linesep}" f"Found 0/1 occurrences of the specific exception: NonExistentError{linesep}" "Found 0/1 test failure output messages."),