Skip to content

Commit 616c090

Browse files
committed
test: fix assert_debug_log call-site bugs, add type checks
Two recently added tests (PR bitcoin#28625 / commit 2e31250 and PR bitcoin#28634 / commit 3bb51c2) introduced a bug by wrongly using the `assert_debug_log` helper. Instead of passing the expected debug string in a list as expected, it was passed as bare string, which is then interpretered as a list of characters, very likely leading the debug log assertion pass even if the intended message is not appearing. In order to avoid bugs like this in the future, enforce that the `{un}expected_msgs` parameters are lists.
1 parent 5ea4fc0 commit 616c090

File tree

4 files changed

+11
-5
lines changed

4 files changed

+11
-5
lines changed

test/functional/feature_assumeutxo.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,7 @@ def test_invalid_snapshot_scenarios(self, valid_snapshot_path):
8282
f.write(bytes.fromhex(bad_snapshot_block_hash)[::-1] + valid_snapshot_contents[32:])
8383

8484
expected_log = f"assumeutxo height in snapshot metadata not recognized ({bad_snapshot_height}) - refusing to load snapshot"
85-
with self.nodes[1].assert_debug_log(expected_log):
85+
with self.nodes[1].assert_debug_log([expected_log]):
8686
assert_raises_rpc_error(-32603, "Unable to load UTXO snapshot", self.nodes[1].loadtxoutset, bad_snapshot_path)
8787

8888
def run_test(self):

test/functional/p2p_segwit.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -706,14 +706,14 @@ def test_p2sh_witness(self):
706706
# segwit activation. Note that older bitcoind's that are not
707707
# segwit-aware would also reject this for failing CLEANSTACK.
708708
with self.nodes[0].assert_debug_log(
709-
expected_msgs=(spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Witness program was passed an empty witness)')):
709+
expected_msgs=[spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Witness program was passed an empty witness)']):
710710
test_transaction_acceptance(self.nodes[0], self.test_node, spend_tx, with_witness=False, accepted=False)
711711

712712
# Try to put the witness script in the scriptSig, should also fail.
713713
spend_tx.vin[0].scriptSig = CScript([p2wsh_pubkey, b'a'])
714714
spend_tx.rehash()
715715
with self.nodes[0].assert_debug_log(
716-
expected_msgs=(spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Script evaluated without error but finished with a false/empty top stack element)')):
716+
expected_msgs=[spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Script evaluated without error but finished with a false/empty top stack element)']):
717717
test_transaction_acceptance(self.nodes[0], self.test_node, spend_tx, with_witness=False, accepted=False)
718718

719719
# Now put the witness script in the witness, should succeed after

test/functional/p2p_v2_transport.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -145,7 +145,7 @@ def run_test(self):
145145
wrong_network_magic_prefix = MAGIC_BYTES["signet"] + V1_PREFIX[4:]
146146
with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
147147
s.connect(("127.0.0.1", p2p_port(0)))
148-
with self.nodes[0].assert_debug_log("V2 transport error: V1 peer with wrong MessageStart"):
148+
with self.nodes[0].assert_debug_log(["V2 transport error: V1 peer with wrong MessageStart"]):
149149
s.sendall(wrong_network_magic_prefix + b"somepayload")
150150

151151
# Check detection of missing garbage terminator (hits after fixed amount of data if terminator never matches garbage)
@@ -156,7 +156,7 @@ def run_test(self):
156156
self.wait_until(lambda: len(self.nodes[0].getpeerinfo()) == num_peers + 1)
157157
s.sendall(b'\x00' * (MAX_KEY_GARB_AND_GARBTERM_LEN - 1))
158158
self.wait_until(lambda: self.nodes[0].getpeerinfo()[-1]["bytesrecv"] == MAX_KEY_GARB_AND_GARBTERM_LEN - 1)
159-
with self.nodes[0].assert_debug_log("V2 transport error: missing garbage terminator"):
159+
with self.nodes[0].assert_debug_log(["V2 transport error: missing garbage terminator"]):
160160
s.sendall(b'\x00') # send out last byte
161161
# should disconnect immediately
162162
self.wait_until(lambda: len(self.nodes[0].getpeerinfo()) == num_peers)

test/functional/test_framework/test_node.py

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -448,6 +448,12 @@ def debug_log_size(self, **kwargs) -> int:
448448
def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
449449
if unexpected_msgs is None:
450450
unexpected_msgs = []
451+
# enforce that `{un}expected_msgs` are lists, in order to avoid bugs where strings
452+
# are passed as arguments, which would be interpreted as lists of single characters
453+
# (likely always passing the debug log assertion)
454+
assert_equal(type(expected_msgs), list)
455+
assert_equal(type(unexpected_msgs), list)
456+
451457
time_end = time.time() + timeout * self.timeout_factor
452458
prev_size = self.debug_log_size(encoding="utf-8") # Must use same encoding that is used to read() below
453459

0 commit comments

Comments
 (0)