From 61f4b9b7ad6e992a9dbbbb091e9b7ba9abe529ac Mon Sep 17 00:00:00 2001 From: virtu Date: Mon, 5 Jun 2023 16:31:31 +0200 Subject: Manage exceptions in bcc callback functions Exceptions are not propagated in ctype callback functions used by bcc. This means an AssertionError exception raised by check_equal() to signal a failed assertion is not getting caught and properly logged. Instead, the error is logged to stdout and execution of the handler stops. The current workaround to check whether all check_equal() assertions in a callback succeeded is to increment a success counter after the assertions (which only gets incremented if none exception is raised and stops execution). Then, outside the callback, the success counter can be used to check whether a callback executed successfully. One issue with the described workaround is that when an exception occurs, there is no way of telling which of the check_equal() statements caused the exception; moreover, there is no way of inspecting how the pieces of data that got compared in check_equal() differed (often a crucial clue when debugging what went wrong). Two fixes to this problem come to mind. The first involves having the callback function make event data accessible outside the callback and inspecting the event using check_equal() outside the callback. This solution still requires a counter in the callback to tell whether a callback was actually executed or if instead the call to perf_buffer_poll() timed out. The second fix entails wrapping all relevant check_equal() statements inside callback functions into try-catch blocks and manually logging AssertionErrors. While not as elegant in terms of design, this approach can be more pragmatic for more complex tests (e.g., ones involving multiple events, events of different types, or the order of events). The solution proposed here is to select the most pragmatic fix on a case-by-case basis: Tests in interface_usdt_net.py, interface_usdt_mempool.py and interface_usdt_validation.py have been refactored to use the first approach, while the second approach was chosen for interface_usdt_utxocache.py (partly to provide a reference for the second approach, but mainly because the utxocache tests are the most intricate tests, and refactoring them to use the first approach would negatively impact their readability). Lastly, interface_usdt_coinselection.py was kept unchanged because it does not use check_equal() statements inside callback functions. --- test/functional/interface_usdt_validation.py | 34 ++++++++++++++-------------- 1 file changed, 17 insertions(+), 17 deletions(-) (limited to 'test/functional/interface_usdt_validation.py') diff --git a/test/functional/interface_usdt_validation.py b/test/functional/interface_usdt_validation.py index 4323aef771..f9d9b525cd 100755 --- a/test/functional/interface_usdt_validation.py +++ b/test/functional/interface_usdt_validation.py @@ -85,13 +85,10 @@ class ValidationTracepointTest(BitcoinTestFramework): self.sigops, self.duration) - # The handle_* function is a ctypes callback function called from C. When - # we assert in the handle_* function, the AssertError doesn't propagate - # back to Python. The exception is ignored. We manually count and assert - # that the handle_* functions succeeded. BLOCKS_EXPECTED = 2 blocks_checked = 0 expected_blocks = dict() + events = [] self.log.info("hook into the validation:block_connected tracepoint") ctx = USDT(pid=self.nodes[0].process.pid) @@ -101,19 +98,10 @@ class ValidationTracepointTest(BitcoinTestFramework): usdt_contexts=[ctx], debug=0) def handle_blockconnected(_, data, __): - nonlocal expected_blocks, blocks_checked + 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() - block = expected_blocks[block_hash] - assert_equal(block["hash"], block_hash) - assert_equal(block["height"], event.height) - assert_equal(len(block["tx"]), event.transactions) - assert_equal(len([tx["vin"] for tx in block["tx"]]), event.inputs) - assert_equal(0, event.sigops) # no sigops in coinbase tx - # only plausibility checks - assert event.duration > 0 - del expected_blocks[block_hash] + events.append(event) blocks_checked += 1 bpf["block_connected"].open_perf_buffer( @@ -126,12 +114,24 @@ class ValidationTracepointTest(BitcoinTestFramework): expected_blocks[block_hash] = self.nodes[0].getblock(block_hash, 2) bpf.perf_buffer_poll(timeout=200) - bpf.cleanup() - self.log.info(f"check that we traced {BLOCKS_EXPECTED} blocks") + self.log.info(f"check that we correctly traced {BLOCKS_EXPECTED} blocks") + for event in events: + block_hash = bytes(event.hash[::-1]).hex() + block = expected_blocks[block_hash] + assert_equal(block["hash"], block_hash) + assert_equal(block["height"], event.height) + assert_equal(len(block["tx"]), event.transactions) + assert_equal(len([tx["vin"] for tx in block["tx"]]), event.inputs) + assert_equal(0, event.sigops) # no sigops in coinbase tx + # only plausibility checks + assert event.duration > 0 + del expected_blocks[block_hash] assert_equal(BLOCKS_EXPECTED, blocks_checked) assert_equal(0, len(expected_blocks)) + bpf.cleanup() + if __name__ == '__main__': ValidationTracepointTest().main() -- cgit v1.2.3