Repository: bitcoin/bitcoin
File: test/functional/feature_framework_startup_failures.py (Python)

Code before:
from hashlib import md5
from os import linesep
import re
import subprocess
import sys
import time

class FeatureFrameworkStartupFailures(BitcoinTestFramework):
    def set_test_params(self):
        self.num_nodes = 1

    def setup_network(self):
        # Don't start the node yet, as we want to measure during run_test.
        self.add_nodes(self.num_nodes, self.extra_args)

    # 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):
        # Inherit args from parent, only modifying tmpdir so children don't fail
        # as a cause of colliding with the parent dir.
        parent_args = sys.argv.copy()
        assert self.options.tmpdir, "Framework should always set tmpdir."
        i, path = next(((i, m[1]) for i, arg in enumerate(parent_args) if (m := re.match(r'--tm(?:p(?:d(?:ir?)?)?)?=(.+)', arg))),
                       (len(parent_args), self.options.tmpdir))
        subdir = md5(expected_exception.encode('utf-8')).hexdigest()[:8]
        parent_args[i:i + 1] = [f"--tmpdir={path}/{subdir}"]
        args = [sys.executable] + parent_args + [f"--internal_test={test.__name__}"] + internal_args

        try:
            # The subprocess encoding argument gives different results for e.output
            # on Linux/Windows, so handle decoding by ourselves for consistency.
            output = subprocess.run(args, timeout=60 * self.options.timeout_factor,
                                    stdout=subprocess.PIPE, stderr=subprocess.STDOUT).stdout.decode("utf-8")
        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

        errors = []
        if (n := output.count("Traceback")) != 1:
            errors.append(f"Found {n}/1 tracebacks - expecting exactly one with no knock-on exceptions.")
        if (n := len(re.findall(expected_exception, output))) != 1:
            errors.append(f"Found {n}/1 occurrences of the specific exception: {expected_exception}")
        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"


Review comment (bug):
In "qa: Handle --timeout-factor=0" 1235a0df5ff6278d07dc95e7acc3ccb14f536286 whats the rationale behind multiplying by factor of 60?

Wondering if this is the right fix? if I pass timeout-factor=99998 the test will fail, but on master I dont think running the functional test with timeout-factor=99998 will trigger any failure.

Code after:
from hashlib import md5
from os import linesep
import re
import subprocess
import sys
import time

class FeatureFrameworkStartupFailures(BitcoinTestFramework):
    def set_test_params(self):
        self.num_nodes = 1

    def setup_network(self):
        # Don't start the node yet, as we want to measure during run_test.
        self.add_nodes(self.num_nodes, self.extra_args)

    # 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):
        # 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

        try:
            # The subprocess encoding argument gives different results for e.output
            # on Linux/Windows, so handle decoding by ourselves for consistency.
            output = subprocess.run(args, timeout=60 * self.options.timeout_factor,
                                    stdout=subprocess.PIPE, stderr=subprocess.STDOUT).stdout.decode("utf-8")
        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

        errors = []
        if (n := output.count("Traceback")) != 1:
            errors.append(f"Found {n}/1 tracebacks - expecting exactly one with no knock-on exceptions.")
        if (n := len(re.findall(expected_exception, output))) != 1:
            errors.append(f"Found {n}/1 occurrences of the specific exception: {expected_exception}")
        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"

    def run_test(self):
        self.log.info("Verifying _verify_startup_failure() functionality (self-check).")
        assert_raises_message(
            AssertionError,