Merge bitcoin/bitcoin#28645: test: fix assert_debug_log call-site b…

…ugs, add type checks

ac4caf3 test: fix `assert_debug_log` call-site bugs, add type checks (Sebastian Falbesoner)

Pull request description:

  Two recently added tests (PR #28625 / commit 2e31250 and PR #28634 / commit 3bb51c2) introduced bugs by wrongly using the `assert_debug_log` helper:

  https://github.com/bitcoin/bitcoin/blob/5ea4fc05edde66c5c90383bc054590dfbdb2b645/test/functional/feature_assumeutxo.py#L84-L85 (already fixed in bitcoin/bitcoin#28639)

  https://github.com/bitcoin/bitcoin/blob/5ea4fc05edde66c5c90383bc054590dfbdb2b645/test/functional/p2p_v2_transport.py#L148
  https://github.com/bitcoin/bitcoin/blob/5ea4fc05edde66c5c90383bc054590dfbdb2b645/test/functional/p2p_v2_transport.py#L159

  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. Thanks to maflcko for discovering: bitcoin/bitcoin#28625 (comment)

  In order to avoid bugs like this in the future, enforce that the `{un}expected_msgs` parameters are lists, as discussed in bitcoin/bitcoin#28625 (comment). Using mypy might be an alternative, but I guess it takes quite a bit of effort to properly integrate this into CI for the whole functional test suite (including taking care of false-positives), so I decided to go with the simpler "manual asserts" hack. Suggestions are very welcome of course.

ACKs for top commit:
  achow101:
    ACK ac4caf3
  maflcko:
    lgtm ACK ac4caf3
  dergoegge:
    ACK ac4caf3

Tree-SHA512: a9677af76a0c370e71f0411339807b1dc6b2a81763db4ec049cd6d766404b916e2bdd002883db5a79c9c388d7d8ebfcbd5f31d43d50be868eeb928e3c906a746

test/functional/p2p_segwit.py

@@ -706,14 +706,14 @@ def test_p2sh_witness(self):
         # segwit activation.  Note that older bitcoind's that are not
         # segwit-aware would also reject this for failing CLEANSTACK.
         with self.nodes[0].assert_debug_log(
-                expected_msgs=(spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Witness program was passed an empty witness)')):
+                expected_msgs=[spend_tx.hash, 'was not accepted: mandatory-script-verify-flag-failed (Witness program was passed an empty witness)']):
             test_transaction_acceptance(self.nodes[0], self.test_node, spend_tx, with_witness=False, accepted=False)
 
         # Try to put the witness script in the scriptSig, should also fail.
         spend_tx.vin[0].scriptSig = CScript([p2wsh_pubkey, b'a'])
         spend_tx.rehash()
         with self.nodes[0].assert_debug_log(
-                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)')):
+                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)']):
             test_transaction_acceptance(self.nodes[0], self.test_node, spend_tx, with_witness=False, accepted=False)
 
         # Now put the witness script in the witness, should succeed after

test/functional/p2p_v2_transport.py

@@ -145,7 +145,7 @@ def run_test(self):
         wrong_network_magic_prefix = MAGIC_BYTES["signet"] + V1_PREFIX[4:]
         with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
             s.connect(("127.0.0.1", p2p_port(0)))
-            with self.nodes[0].assert_debug_log("V2 transport error: V1 peer with wrong MessageStart"):
+            with self.nodes[0].assert_debug_log(["V2 transport error: V1 peer with wrong MessageStart"]):
                 s.sendall(wrong_network_magic_prefix + b"somepayload")
 
         # 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):
             self.wait_until(lambda: len(self.nodes[0].getpeerinfo()) == num_peers + 1)
             s.sendall(b'\x00' * (MAX_KEY_GARB_AND_GARBTERM_LEN - 1))
             self.wait_until(lambda: self.nodes[0].getpeerinfo()[-1]["bytesrecv"] == MAX_KEY_GARB_AND_GARBTERM_LEN - 1)
-            with self.nodes[0].assert_debug_log("V2 transport error: missing garbage terminator"):
+            with self.nodes[0].assert_debug_log(["V2 transport error: missing garbage terminator"]):
                 s.sendall(b'\x00')  # send out last byte
                 # should disconnect immediately
                 self.wait_until(lambda: len(self.nodes[0].getpeerinfo()) == num_peers)

test/functional/test_framework/test_node.py

@@ -448,6 +448,9 @@ def debug_log_size(self, **kwargs) -> int:
     def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
         if unexpected_msgs is None:
             unexpected_msgs = []
+        assert_equal(type(expected_msgs), list)
+        assert_equal(type(unexpected_msgs), list)
+
         time_end = time.time() + timeout * self.timeout_factor
         prev_size = self.debug_log_size(encoding="utf-8")  # Must use same encoding that is used to read() below