Merge bitcoin#27944: test: various USDT functional test cleanups (27831 follow-ups)

9f55773 test: refactor: usdt_mempool: store all events (stickies-v)
bc43270 test: refactor: remove unnecessary nonlocal (stickies-v)
326db63 test: log sanity check assertion failures (stickies-v)
f5525ad test: store utxocache events (stickies-v)
f1b99ac test: refactor: deduplicate handle_utxocache_* logic (stickies-v)
ad90ba3 test: refactor:  rename inbound to is_inbound (stickies-v)
afc0224 test: refactor: remove unnecessary blocks_checked counter (stickies-v)

Pull request description:

  Various cleanups to the USDT functional tests, largely (but not exclusively) follow-ups to bitcoin#27831 (review). Except for slightly different logging behaviour in "test: store utxocache events" and "test: log sanity check assertion failures", this is a refactor PR, removing unnecessary code and (imo) making it more readable and maintainable.

  The rationale for each change is in the corresponding commit message.

  Note: except for "test: store utxocache events" (which relies on its parent, and I separated into two commits because we may want the parent but not the child), all commits are stand-alone and I'm okay with dropping one/multiple commits if they turn out to be controversial or undesired.

ACKs for top commit:
  0xB10C:
    ACK 9f55773. Reviewed the code and ran the USDT interface tests. I stepped through the commits and think all changes are reasonable.

Tree-SHA512: 6c37a0265b6c26d4f9552a056a690b8f86f7304bd33b4419febd8b17369cf6af799cb87c16df35d0c2a1b839ad31de24661d4384eafa88816c2051c522fd3bf5

Author: fanquake

test/functional/interface_usdt_net.py

@@ -121,25 +121,24 @@ def __repr__(self):
         checked_outbound_version_msg = 0
         events = []
 
-        def check_p2p_message(event, inbound):
+        def check_p2p_message(event, is_inbound):
             nonlocal checked_inbound_version_msg, checked_outbound_version_msg
             if event.msg_type.decode("utf-8") == "version":
                 self.log.info(
-                    f"check_p2p_message(): {'inbound' if inbound else 'outbound'} {event}")
+                    f"check_p2p_message(): {'inbound' if is_inbound else 'outbound'} {event}")
                 peer = self.nodes[0].getpeerinfo()[0]
                 msg = msg_version()
                 msg.deserialize(BytesIO(bytes(event.msg[:event.msg_size])))
                 assert_equal(peer["id"], event.peer_id, peer["id"])
                 assert_equal(peer["addr"], event.peer_addr.decode("utf-8"))
                 assert_equal(peer["connection_type"],
                              event.peer_conn_type.decode("utf-8"))
-                if inbound:
+                if is_inbound:
                     checked_inbound_version_msg += 1
                 else:
                     checked_outbound_version_msg += 1
 
         def handle_inbound(_, data, __):
-            nonlocal events
             event = ctypes.cast(data, ctypes.POINTER(P2PMessage)).contents
             events.append((event, True))
 
@@ -157,8 +156,8 @@ def handle_outbound(_, data, __):
 
         self.log.info(
             "check receipt and content of in- and outbound version messages")
-        for event, inbound in events:
-            check_p2p_message(event, inbound)
+        for event, is_inbound in events:
+            check_p2p_message(event, is_inbound)
         assert_equal(EXPECTED_INOUTBOUND_VERSION_MSG,
                      checked_inbound_version_msg)
         assert_equal(EXPECTED_INOUTBOUND_VERSION_MSG,

test/functional/interface_usdt_utxocache.py

@@ -254,43 +254,30 @@ def test_add_spent(self):
         # that the handle_* functions succeeded.
         EXPECTED_HANDLE_ADD_SUCCESS = 2
         EXPECTED_HANDLE_SPENT_SUCCESS = 1
-        handle_add_succeeds = 0
-        handle_spent_succeeds = 0
 
-        expected_utxocache_spents = []
         expected_utxocache_adds = []
+        expected_utxocache_spents = []
+
+        actual_utxocache_adds = []
+        actual_utxocache_spents = []
+
+        def compare_utxo_with_event(utxo, event):
+            """Compare a utxo dict to the event produced by BPF"""
+            assert_equal(utxo["txid"], bytes(event.txid[::-1]).hex())
+            assert_equal(utxo["index"], event.index)
+            assert_equal(utxo["height"], event.height)
+            assert_equal(utxo["value"], event.value)
+            assert_equal(utxo["is_coinbase"], event.is_coinbase)
 
         def handle_utxocache_add(_, data, __):
-            nonlocal handle_add_succeeds
             event = ctypes.cast(data, ctypes.POINTER(UTXOCacheChange)).contents
             self.log.info(f"handle_utxocache_add(): {event}")
-            add = expected_utxocache_adds.pop(0)
-            try:
-                assert_equal(add["txid"], bytes(event.txid[::-1]).hex())
-                assert_equal(add["index"], event.index)
-                assert_equal(add["height"], event.height)
-                assert_equal(add["value"], event.value)
-                assert_equal(add["is_coinbase"], event.is_coinbase)
-            except AssertionError:
-                self.log.exception("Assertion failed")
-            else:
-                handle_add_succeeds += 1
+            actual_utxocache_adds.append(event)
 
         def handle_utxocache_spent(_, data, __):
-            nonlocal handle_spent_succeeds
             event = ctypes.cast(data, ctypes.POINTER(UTXOCacheChange)).contents
             self.log.info(f"handle_utxocache_spent(): {event}")
-            spent = expected_utxocache_spents.pop(0)
-            try:
-                assert_equal(spent["txid"], bytes(event.txid[::-1]).hex())
-                assert_equal(spent["index"], event.index)
-                assert_equal(spent["height"], event.height)
-                assert_equal(spent["value"], event.value)
-                assert_equal(spent["is_coinbase"], event.is_coinbase)
-            except AssertionError:
-                self.log.exception("Assertion failed")
-            else:
-                handle_spent_succeeds += 1
+            actual_utxocache_spents.append(event)
 
         bpf["utxocache_add"].open_perf_buffer(handle_utxocache_add)
         bpf["utxocache_spent"].open_perf_buffer(handle_utxocache_spent)
@@ -326,19 +313,18 @@ def handle_utxocache_spent(_, data, __):
                         "is_coinbase": block_index == 0,
                     })
 
-        assert_equal(EXPECTED_HANDLE_ADD_SUCCESS, len(expected_utxocache_adds))
-        assert_equal(EXPECTED_HANDLE_SPENT_SUCCESS,
-                     len(expected_utxocache_spents))
-
         bpf.perf_buffer_poll(timeout=200)
-        bpf.cleanup()
+
+        assert_equal(EXPECTED_HANDLE_ADD_SUCCESS, len(expected_utxocache_adds), len(actual_utxocache_adds))
+        assert_equal(EXPECTED_HANDLE_SPENT_SUCCESS, len(expected_utxocache_spents), len(actual_utxocache_spents))
 
         self.log.info(
             f"check that we successfully traced {EXPECTED_HANDLE_ADD_SUCCESS} adds and {EXPECTED_HANDLE_SPENT_SUCCESS} spent")
-        assert_equal(0, len(expected_utxocache_adds))
-        assert_equal(0, len(expected_utxocache_spents))
-        assert_equal(EXPECTED_HANDLE_ADD_SUCCESS, handle_add_succeeds)
-        assert_equal(EXPECTED_HANDLE_SPENT_SUCCESS, handle_spent_succeeds)
+        for expected_utxo, actual_event in zip(expected_utxocache_adds + expected_utxocache_spents,
+                                               actual_utxocache_adds + actual_utxocache_spents):
+            compare_utxo_with_event(expected_utxo, actual_event)
+
+        bpf.cleanup()
 
     def test_flush(self):
         """ Tests the utxocache:flush tracepoint API.
@@ -368,9 +354,13 @@ def handle_utxocache_flush(_, data, __):
             assert_equal(expected["mode"], FLUSHMODE_NAME[event.mode])
             possible_cache_sizes.remove(event.size)  # fails if size not in set
             # sanity checks only
-            assert(event.memory > 0)
-            assert(event.duration > 0)
-            handle_flush_succeeds += 1
+            try:
+                assert event.memory > 0
+                assert event.duration > 0
+            except AssertionError:
+                self.log.exception("Assertion error")
+            else:
+                handle_flush_succeeds += 1
 
         bpf["utxocache_flush"].open_perf_buffer(handle_utxocache_flush)
 

test/functional/interface_usdt_validation.py

@@ -86,7 +86,6 @@ def __repr__(self):
                     self.duration)
 
         BLOCKS_EXPECTED = 2
-        blocks_checked = 0
         expected_blocks = dict()
         events = []
 
@@ -98,7 +97,6 @@ def __repr__(self):
                   usdt_contexts=[ctx], debug=0, cflags=["-Wno-error=implicit-function-declaration"])
 
         def handle_blockconnected(_, data, __):
-            nonlocal events, blocks_checked
             event = ctypes.cast(data, ctypes.POINTER(Block)).contents
             self.log.info(f"handle_blockconnected(): {event}")
             block_hash = bytes(event.hash[::-1]).hex()
@@ -111,7 +109,6 @@ def handle_blockconnected(_, data, __):
             # only plausibility checks
             assert(event.duration > 0)
             del expected_blocks[block_hash]
-            blocks_checked += 1
 
         bpf["block_connected"].open_perf_buffer(
             handle_blockconnected)
@@ -136,7 +133,7 @@ def handle_blockconnected(_, data, __):
             # only plausibility checks
             assert event.duration > 0
             del expected_blocks[block_hash]
-        assert_equal(BLOCKS_EXPECTED, blocks_checked)
+        assert_equal(BLOCKS_EXPECTED, len(events))
         assert_equal(0, len(expected_blocks))
 
         bpf.cleanup()