1 #!/usr/bin/env python3
2 # Copyright (c) 2025-present The Bitcoin Core developers
3 # Distributed under the MIT software license, see the accompanying
4 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
5 """
6 Verify framework startup failures only raise one exception since
7 multiple exceptions being raised muddies the waters of what actually
8 went wrong. We should maintain this bar of only raising one exception as
9 long as additional maintenance and complexity is low.
10 11 Test relaunches itself into child processes in order to trigger failures
12 without the parent process' BitcoinTestFramework also failing.
13 """
14 15 from test_framework.util import (
16 assert_raises_message,
17 rpc_port,
18 )
19 from test_framework.test_framework import BitcoinTestFramework
20 21 from hashlib import md5
22 from os import linesep
23 import re
24 import subprocess
25 import sys
26 import time
27 28 class FeatureFrameworkStartupFailures(BitcoinTestFramework):
29 def set_test_params(self):
30 self.num_nodes = 1
31 32 def setup_network(self):
33 # Don't start the node yet, as we want to measure during run_test.
34 self.add_nodes(self.num_nodes, self.extra_args)
35 36 # Launches a child test process that runs this same file, but instantiates
37 # a child test. Verifies that it raises only the expected exception, once.
38 def _verify_startup_failure(self, test, internal_args, expected_exception):
39 name = test.__name__
40 def format_child_output(output):
41 return f"\n<{name} OUTPUT BEGIN>\n{output.strip()}\n<{name} OUTPUT END>\n"
42 43 # Inherit sys.argv from parent, only overriding tmpdir to a subdirectory
44 # so children don't fail due to colliding with the parent dir.
45 assert self.options.tmpdir, "Framework should always set tmpdir."
46 subdir = md5(expected_exception.encode('utf-8')).hexdigest()[:8]
47 args = [sys.executable] + sys.argv + [f"--tmpdir={self.options.tmpdir}/{subdir}", f"--internal_test={name}"] + internal_args
48 49 try:
50 output = subprocess.run(args, timeout=60 * self.options.timeout_factor,
51 stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True).stdout
52 except subprocess.TimeoutExpired as e:
53 sys.exit("Unexpected child process timeout!\n"
54 "WARNING: Timeouts like this halt execution of TestNode logic, "
55 "meaning dangling bitcoind processes are to be expected.\n" +
56 (format_child_output(e.output.decode("utf-8")) if e.output else "<EMPTY OUTPUT>"))
57 58 errors = []
59 if (n := output.count("Traceback")) != 1:
60 errors.append(f"Found {n}/1 tracebacks - expecting exactly one with no knock-on exceptions.")
61 if (n := len(re.findall(expected_exception, output))) != 1:
62 errors.append(f"Found {n}/1 occurrences of the specific exception: {expected_exception}")
63 if (n := output.count("Test failed. Test logging available at")) != 1:
64 errors.append(f"Found {n}/1 test failure output messages.")
65 66 assert not errors, (f"Child test did NOT contain (only) expected errors:\n{linesep.join(errors)}\n" +
67 format_child_output(output))
68 69 self.log.debug("Child test did contain (only) expected errors:\n" +
70 format_child_output(output))
71 72 def run_test(self):
73 self.log.info("Verifying _verify_startup_failure() functionality (self-check).")
74 assert_raises_message(
75 AssertionError,
76 ( "Child test did NOT contain (only) expected errors:\n"
77 f"Found 0/1 tracebacks - expecting exactly one with no knock-on exceptions.{linesep}"
78 f"Found 0/1 occurrences of the specific exception: NonExistentError{linesep}"
79 "Found 0/1 test failure output messages."),
80 self._verify_startup_failure,
81 TestSuccess, [],
82 "NonExistentError",
83 )
84 85 self.log.info("Parent process is measuring node startup duration in order to obtain a reasonable timeout value for later tests...")
86 node_start_time = time.time()
87 self.nodes[0].start()
88 self.nodes[0].wait_for_rpc_connection()
89 node_start_duration = time.time() - node_start_time
90 self.nodes[0].stop_node()
91 self.log.info(f"...measured {node_start_duration:.1f}s.")
92 93 self.log.info("Verifying inability to connect to bitcoind's RPC interface due to wrong port results in one exception containing at least one OSError.")
94 self._verify_startup_failure(
95 TestWrongRpcPortStartupFailure, [f"--internal_node_start_duration={node_start_duration}"],
96 r"AssertionError: \[node 0\] Unable to connect to bitcoind after \d+s \(ignored errors: {[^}]*'OSError \w+'?: \d+[^}]*}, latest: '[\w ]+'/\w+\([^)]+\)\)"
97 )
98 99 self.log.info("Verifying timeout while waiting for init errors that do not occur results in only one exception.")
100 self._verify_startup_failure(
101 TestMissingInitErrorTimeout, [f"--internal_node_start_duration={node_start_duration}"],
102 r"AssertionError: \[node 0\] bitcoind should have exited within \d+s with an error \(cmd:"
103 )
104 105 self.log.info("Verifying startup failure due to invalid arg results in only one exception.")
106 self._verify_startup_failure(
107 TestInitErrorStartupFailure, [],
108 r"FailedToStartError: \[node 0\] bitcoind exited with status 1 during initialization\. Error: Error parsing command line arguments: Invalid parameter -nonexistentarg"
109 )
110 111 self.log.info("Verifying start() then stop_node() on a node without wait_for_rpc_connection() in between raises an assert.")
112 self._verify_startup_failure(
113 TestStartStopStartupFailure, [],
114 r"AssertionError: \[node 0\] Should only call stop_node\(\) on a running node after wait_for_rpc_connection\(\) succeeded\. Did you forget to call the latter after start\(\)\? Not connected to process: \d+"
115 )
116 117 class InternalTestMixin:
118 def add_options(self, parser):
119 # Just here to silence unrecognized argument error, we actually read the value in the if-main at the bottom.
120 parser.add_argument("--internal_test", dest="internal_never_read", help="ONLY TO BE USED WHEN TEST RELAUNCHES ITSELF")
121 122 class InternalDurationTestMixin(InternalTestMixin):
123 def add_options(self, parser):
124 # Receives the previously measured duration for node startup + RPC connection establishment.
125 parser.add_argument("--internal_node_start_duration", dest="node_start_duration", help="ONLY TO BE USED WHEN TEST RELAUNCHES ITSELF", type=float)
126 InternalTestMixin.add_options(self, parser)
127 128 def get_reasonable_rpc_timeout(self):
129 # 2 * the measured test startup duration should be enough.
130 # Divide by timeout_factor to counter multiplication in BitcoinTestFramework.
131 return max(3, 2 * self.options.node_start_duration) / self.options.timeout_factor
132 133 class TestWrongRpcPortStartupFailure(InternalDurationTestMixin, BitcoinTestFramework):
134 def set_test_params(self):
135 self.num_nodes = 1
136 # Override RPC listen port to something TestNode isn't expecting so that
137 # we are unable to establish an RPC connection.
138 self.extra_args = [[f"-rpcport={rpc_port(2)}"]]
139 # Override the timeout to avoid waiting unnecessarily long to realize
140 # nothing is on that port.
141 self.rpc_timeout = self.get_reasonable_rpc_timeout()
142 143 def run_test(self):
144 assert False, "Should have failed earlier during startup."
145 146 class TestMissingInitErrorTimeout(InternalDurationTestMixin, BitcoinTestFramework):
147 def set_test_params(self):
148 self.num_nodes = 1
149 # Override the timeout to avoid waiting unnecessarily long for an init
150 # error which never occurs.
151 self.rpc_timeout = self.get_reasonable_rpc_timeout()
152 153 def setup_network(self):
154 self.add_nodes(self.num_nodes, self.extra_args)
155 self.nodes[0].assert_start_raises_init_error()
156 assert False, "assert_start_raises_init_error() should raise an exception due to timeout since we don't expect an init error."
157 158 def run_test(self):
159 assert False, "Should have failed earlier during startup."
160 161 class TestInitErrorStartupFailure(InternalTestMixin, BitcoinTestFramework):
162 def set_test_params(self):
163 self.num_nodes = 1
164 self.extra_args = [["-nonexistentarg"]]
165 166 def run_test(self):
167 assert False, "Should have failed earlier during startup."
168 169 class TestStartStopStartupFailure(InternalTestMixin, BitcoinTestFramework):
170 def set_test_params(self):
171 self.num_nodes = 1
172 173 def setup_network(self):
174 self.add_nodes(self.num_nodes, self.extra_args)
175 self.nodes[0].start()
176 self.nodes[0].stop_node()
177 assert False, "stop_node() should raise an exception when we haven't called wait_for_rpc_connection()"
178 179 def run_test(self):
180 assert False, "Should have failed earlier during startup."
181 182 class TestSuccess(InternalTestMixin, BitcoinTestFramework):
183 def set_test_params(self):
184 self.num_nodes = 1
185 186 def setup_network(self):
187 pass # Don't need to start our node.
188 189 def run_test(self):
190 pass # Just succeed.
191 192 193 if __name__ == '__main__':
194 if class_name := next((m[1] for arg in sys.argv[1:] if (m := re.match(r'--internal_test=(.+)', arg))), None):
195 internal_test = globals().get(class_name)
196 assert internal_test, f"Unrecognized test: {class_name}"
197 internal_test(__file__).main()
198 else:
199 FeatureFrameworkStartupFailures(__file__).main()
200