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.
This commit is contained in:
Hodlinator
2025-07-08 23:14:47 +02:00
parent 7427a03b5a
commit 356883f0e4

View File

@@ -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"<CHILD OUTPUT BEGIN>\n{e.output.decode("utf-8")}\n<CHILD OUTPUT END>",
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 "<EMPTY OUTPUT>"))
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<CHILD OUTPUT BEGIN>\n{output}\n<CHILD OUTPUT END>\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."),