aboutsummaryrefslogtreecommitdiff
path: root/test/functional/interface_usdt_utxocache.py
diff options
context:
space:
mode:
Diffstat (limited to 'test/functional/interface_usdt_utxocache.py')
-rwxr-xr-xtest/functional/interface_usdt_utxocache.py410
1 files changed, 410 insertions, 0 deletions
diff --git a/test/functional/interface_usdt_utxocache.py b/test/functional/interface_usdt_utxocache.py
new file mode 100755
index 0000000000..2280de1479
--- /dev/null
+++ b/test/functional/interface_usdt_utxocache.py
@@ -0,0 +1,410 @@
+#!/usr/bin/env python3
+# Copyright (c) 2022 The Bitcoin Core developers
+# Distributed under the MIT software license, see the accompanying
+# file COPYING or http://www.opensource.org/licenses/mit-license.php.
+
+""" Tests the utxocache:* tracepoint API interface.
+ See https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#context-utxocache
+"""
+
+import ctypes
+# Test will be skipped if we don't have bcc installed
+try:
+ from bcc import BPF, USDT # type: ignore[import]
+except ImportError:
+ pass
+from test_framework.messages import COIN
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import assert_equal
+from test_framework.wallet import MiniWallet
+
+utxocache_changes_program = """
+#include <uapi/linux/ptrace.h>
+
+typedef signed long long i64;
+
+struct utxocache_change
+{
+ char txid[32];
+ u32 index;
+ u32 height;
+ i64 value;
+ bool is_coinbase;
+};
+
+BPF_PERF_OUTPUT(utxocache_add);
+int trace_utxocache_add(struct pt_regs *ctx) {
+ struct utxocache_change add = {};
+ bpf_usdt_readarg_p(1, ctx, &add.txid, 32);
+ bpf_usdt_readarg(2, ctx, &add.index);
+ bpf_usdt_readarg(3, ctx, &add.height);
+ bpf_usdt_readarg(4, ctx, &add.value);
+ bpf_usdt_readarg(5, ctx, &add.is_coinbase);
+ utxocache_add.perf_submit(ctx, &add, sizeof(add));
+ return 0;
+}
+
+BPF_PERF_OUTPUT(utxocache_spent);
+int trace_utxocache_spent(struct pt_regs *ctx) {
+ struct utxocache_change spent = {};
+ bpf_usdt_readarg_p(1, ctx, &spent.txid, 32);
+ bpf_usdt_readarg(2, ctx, &spent.index);
+ bpf_usdt_readarg(3, ctx, &spent.height);
+ bpf_usdt_readarg(4, ctx, &spent.value);
+ bpf_usdt_readarg(5, ctx, &spent.is_coinbase);
+ utxocache_spent.perf_submit(ctx, &spent, sizeof(spent));
+ return 0;
+}
+
+BPF_PERF_OUTPUT(utxocache_uncache);
+int trace_utxocache_uncache(struct pt_regs *ctx) {
+ struct utxocache_change uncache = {};
+ bpf_usdt_readarg_p(1, ctx, &uncache.txid, 32);
+ bpf_usdt_readarg(2, ctx, &uncache.index);
+ bpf_usdt_readarg(3, ctx, &uncache.height);
+ bpf_usdt_readarg(4, ctx, &uncache.value);
+ bpf_usdt_readarg(5, ctx, &uncache.is_coinbase);
+ utxocache_uncache.perf_submit(ctx, &uncache, sizeof(uncache));
+ return 0;
+}
+"""
+
+utxocache_flushes_program = """
+#include <uapi/linux/ptrace.h>
+
+typedef signed long long i64;
+
+struct utxocache_flush
+{
+ i64 duration;
+ u32 mode;
+ u64 size;
+ u64 memory;
+ bool for_prune;
+};
+
+BPF_PERF_OUTPUT(utxocache_flush);
+int trace_utxocache_flush(struct pt_regs *ctx) {
+ struct utxocache_flush flush = {};
+ bpf_usdt_readarg(1, ctx, &flush.duration);
+ bpf_usdt_readarg(2, ctx, &flush.mode);
+ bpf_usdt_readarg(3, ctx, &flush.size);
+ bpf_usdt_readarg(4, ctx, &flush.memory);
+ bpf_usdt_readarg(5, ctx, &flush.for_prune);
+ utxocache_flush.perf_submit(ctx, &flush, sizeof(flush));
+ return 0;
+}
+"""
+
+FLUSHMODE_NAME = {
+ 0: "NONE",
+ 1: "IF_NEEDED",
+ 2: "PERIODIC",
+ 3: "ALWAYS",
+}
+
+
+class UTXOCacheChange(ctypes.Structure):
+ _fields_ = [
+ ("txid", ctypes.c_ubyte * 32),
+ ("index", ctypes.c_uint32),
+ ("height", ctypes.c_uint32),
+ ("value", ctypes.c_uint64),
+ ("is_coinbase", ctypes.c_bool),
+ ]
+
+ def __repr__(self):
+ return f"UTXOCacheChange(outpoint={bytes(self.txid[::-1]).hex()}:{self.index}, height={self.height}, value={self.value}sat, is_coinbase={self.is_coinbase})"
+
+
+class UTXOCacheFlush(ctypes.Structure):
+ _fields_ = [
+ ("duration", ctypes.c_int64),
+ ("mode", ctypes.c_uint32),
+ ("size", ctypes.c_uint64),
+ ("memory", ctypes.c_uint64),
+ ("for_prune", ctypes.c_bool),
+ ]
+
+ def __repr__(self):
+ return f"UTXOCacheFlush(duration={self.duration}, mode={FLUSHMODE_NAME[self.mode]}, size={self.size}, memory={self.memory}, for_prune={self.for_prune})"
+
+
+class UTXOCacheTracepointTest(BitcoinTestFramework):
+ def set_test_params(self):
+ self.setup_clean_chain = False
+ self.num_nodes = 1
+ self.extra_args = [["-txindex"]]
+
+ def skip_test_if_missing_module(self):
+ self.skip_if_platform_not_linux()
+ self.skip_if_no_bitcoind_tracepoints()
+ self.skip_if_no_python_bcc()
+ self.skip_if_no_bpf_permissions()
+
+ def run_test(self):
+ self.wallet = MiniWallet(self.nodes[0])
+ self.generate(self.wallet, 101)
+
+ self.test_uncache()
+ self.test_add_spent()
+ self.test_flush()
+
+ def test_uncache(self):
+ """ Tests the utxocache:uncache tracepoint API.
+ https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#tracepoint-utxocacheuncache
+ """
+ # To trigger an UTXO uncache from the cache, we create an invalid transaction
+ # spending a not-cached, but existing UTXO. During transaction validation, this
+ # the UTXO is added to the utxo cache, but as the transaction is invalid, it's
+ # uncached again.
+ self.log.info("testing the utxocache:uncache tracepoint API")
+
+ # Retrieve the txid for the UTXO created in the first block. This UTXO is not
+ # in our UTXO cache.
+ EARLY_BLOCK_HEIGHT = 1
+ block_1_hash = self.nodes[0].getblockhash(EARLY_BLOCK_HEIGHT)
+ block_1 = self.nodes[0].getblock(block_1_hash)
+ block_1_coinbase_txid = block_1["tx"][0]
+
+ # Create a transaction and invalidate it by changing the txid of the previous
+ # output to the coinbase txid of the block at height 1.
+ invalid_tx = self.wallet.create_self_transfer()["tx"]
+ invalid_tx.vin[0].prevout.hash = int(block_1_coinbase_txid, 16)
+
+ self.log.info("hooking into the utxocache:uncache tracepoint")
+ ctx = USDT(pid=self.nodes[0].process.pid)
+ ctx.enable_probe(probe="utxocache:uncache",
+ fn_name="trace_utxocache_uncache")
+ bpf = BPF(text=utxocache_changes_program, usdt_contexts=[ctx], debug=0)
+
+ # 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.
+ EXPECTED_HANDLE_UNCACHE_SUCCESS = 1
+ handle_uncache_succeeds = 0
+
+ def handle_utxocache_uncache(_, data, __):
+ nonlocal handle_uncache_succeeds
+ event = ctypes.cast(data, ctypes.POINTER(UTXOCacheChange)).contents
+ self.log.info(f"handle_utxocache_uncache(): {event}")
+ assert_equal(block_1_coinbase_txid, bytes(event.txid[::-1]).hex())
+ assert_equal(0, event.index) # prevout index
+ assert_equal(EARLY_BLOCK_HEIGHT, event.height)
+ assert_equal(50 * COIN, event.value)
+ assert_equal(True, event.is_coinbase)
+
+ handle_uncache_succeeds += 1
+
+ bpf["utxocache_uncache"].open_perf_buffer(handle_utxocache_uncache)
+
+ self.log.info(
+ "testmempoolaccept the invalid transaction to trigger an UTXO-cache uncache")
+ result = self.nodes[0].testmempoolaccept(
+ [invalid_tx.serialize().hex()])[0]
+ assert_equal(result["allowed"], False)
+
+ bpf.perf_buffer_poll(timeout=100)
+ bpf.cleanup()
+
+ self.log.info(
+ f"check that we successfully traced {EXPECTED_HANDLE_UNCACHE_SUCCESS} uncaches")
+ assert_equal(EXPECTED_HANDLE_UNCACHE_SUCCESS, handle_uncache_succeeds)
+
+ def test_add_spent(self):
+ """ Tests the utxocache:add utxocache:spent tracepoint API
+ See https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#tracepoint-utxocacheadd
+ and https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#tracepoint-utxocachespent
+ """
+
+ self.log.info(
+ "test the utxocache:add and utxocache:spent tracepoint API")
+
+ self.log.info("create an unconfirmed transaction")
+ self.wallet.send_self_transfer(from_node=self.nodes[0])
+
+ # We mine a block to trace changes (add/spent) to the active in-memory cache
+ # of the UTXO set (see CoinsTip() of CCoinsViewCache). However, in some cases
+ # temporary clones of the active cache are made. For example, during mining with
+ # the generate RPC call, the block is first tested in TestBlockValidity(). There,
+ # a clone of the active cache is modified during a test ConnectBlock() call.
+ # These are implementation details we don't want to test here. Thus, after
+ # mining, we invalidate the block, start the tracing, and then trace the cache
+ # changes to the active utxo cache.
+ self.log.info("mine and invalidate a block that is later reconsidered")
+ block_hash = self.generate(self.wallet, 1)[0]
+ self.nodes[0].invalidateblock(block_hash)
+
+ self.log.info(
+ "hook into the utxocache:add and utxocache:spent tracepoints")
+ ctx = USDT(pid=self.nodes[0].process.pid)
+ ctx.enable_probe(probe="utxocache:add", fn_name="trace_utxocache_add")
+ ctx.enable_probe(probe="utxocache:spent",
+ fn_name="trace_utxocache_spent")
+ bpf = BPF(text=utxocache_changes_program, usdt_contexts=[ctx], debug=0)
+
+ # 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.
+ EXPECTED_HANDLE_ADD_SUCCESS = 2
+ EXPECTED_HANDLE_SPENT_SUCCESS = 1
+ handle_add_succeeds = 0
+ handle_spent_succeeds = 0
+
+ expected_utxocache_spents = []
+ expected_utxocache_adds = []
+
+ 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)
+ 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)
+ handle_add_succeeds += 1
+
+ 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)
+ 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)
+ handle_spent_succeeds += 1
+
+ bpf["utxocache_add"].open_perf_buffer(handle_utxocache_add)
+ bpf["utxocache_spent"].open_perf_buffer(handle_utxocache_spent)
+
+ # We trigger a block re-connection. This causes changes (add/spent)
+ # to the UTXO-cache which in turn triggers the tracepoints.
+ self.log.info("reconsider the previously invalidated block")
+ self.nodes[0].reconsiderblock(block_hash)
+
+ block = self.nodes[0].getblock(block_hash, 2)
+ for (block_index, tx) in enumerate(block["tx"]):
+ for vin in tx["vin"]:
+ if "coinbase" not in vin:
+ prevout_tx = self.nodes[0].getrawtransaction(
+ vin["txid"], True)
+ prevout_tx_block = self.nodes[0].getblockheader(
+ prevout_tx["blockhash"])
+ spends_coinbase = "coinbase" in prevout_tx["vin"][0]
+ expected_utxocache_spents.append({
+ "txid": vin["txid"],
+ "index": vin["vout"],
+ "height": prevout_tx_block["height"],
+ "value": int(prevout_tx["vout"][vin["vout"]]["value"] * COIN),
+ "is_coinbase": spends_coinbase,
+ })
+ for (i, vout) in enumerate(tx["vout"]):
+ if vout["scriptPubKey"]["type"] != "nulldata":
+ expected_utxocache_adds.append({
+ "txid": tx["txid"],
+ "index": i,
+ "height": block["height"],
+ "value": int(vout["value"] * COIN),
+ "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()
+
+ 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)
+
+ def test_flush(self):
+ """ Tests the utxocache:flush tracepoint API.
+ See https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#tracepoint-utxocacheflush"""
+
+ self.log.info("test the utxocache:flush tracepoint API")
+ self.log.info("hook into the utxocache:flush tracepoint")
+ ctx = USDT(pid=self.nodes[0].process.pid)
+ ctx.enable_probe(probe="utxocache:flush",
+ fn_name="trace_utxocache_flush")
+ bpf = BPF(text=utxocache_flushes_program, usdt_contexts=[ctx], debug=0)
+
+ # 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.
+ EXPECTED_HANDLE_FLUSH_SUCCESS = 3
+ handle_flush_succeeds = 0
+ expected_flushes = list()
+
+ def handle_utxocache_flush(_, data, __):
+ nonlocal handle_flush_succeeds
+ event = ctypes.cast(data, ctypes.POINTER(UTXOCacheFlush)).contents
+ self.log.info(f"handle_utxocache_flush(): {event}")
+ expected_flushes.remove({
+ "mode": FLUSHMODE_NAME[event.mode],
+ "for_prune": event.for_prune,
+ "size": event.size
+ })
+ # sanity checks only
+ assert(event.memory > 0)
+ assert(event.duration > 0)
+ handle_flush_succeeds += 1
+
+ bpf["utxocache_flush"].open_perf_buffer(handle_utxocache_flush)
+
+ self.log.info("stop the node to flush the UTXO cache")
+ UTXOS_IN_CACHE = 2 # might need to be changed if the eariler tests are modified
+ # A node shutdown causes two flushes. One that flushes UTXOS_IN_CACHE
+ # UTXOs and one that flushes 0 UTXOs. Normally the 0-UTXO-flush is the
+ # second flush, however it can happen that the order changes.
+ expected_flushes.append({"mode": "ALWAYS", "for_prune": False, "size": UTXOS_IN_CACHE})
+ expected_flushes.append({"mode": "ALWAYS", "for_prune": False, "size": 0})
+ self.stop_node(0)
+
+ bpf.perf_buffer_poll(timeout=200)
+ bpf.cleanup()
+
+ self.log.info("check that we don't expect additional flushes")
+ assert_equal(0, len(expected_flushes))
+
+ self.log.info("restart the node with -prune")
+ self.start_node(0, ["-fastprune=1", "-prune=1"])
+
+ BLOCKS_TO_MINE = 350
+ self.log.info(f"mine {BLOCKS_TO_MINE} blocks to be able to prune")
+ self.generate(self.wallet, BLOCKS_TO_MINE)
+
+ self.log.info("test the utxocache:flush tracepoint API with pruning")
+ self.log.info("hook into the utxocache:flush tracepoint")
+ ctx = USDT(pid=self.nodes[0].process.pid)
+ ctx.enable_probe(probe="utxocache:flush",
+ fn_name="trace_utxocache_flush")
+ bpf = BPF(text=utxocache_flushes_program, usdt_contexts=[ctx], debug=0)
+ bpf["utxocache_flush"].open_perf_buffer(handle_utxocache_flush)
+
+ self.log.info(f"prune blockchain to trigger a flush for pruning")
+ expected_flushes.append({"mode": "NONE", "for_prune": True, "size": 0})
+ self.nodes[0].pruneblockchain(315)
+
+ bpf.perf_buffer_poll(timeout=500)
+ bpf.cleanup()
+
+ self.log.info(
+ f"check that we don't expect additional flushes and that the handle_* function succeeded")
+ assert_equal(0, len(expected_flushes))
+ assert_equal(EXPECTED_HANDLE_FLUSH_SUCCESS, handle_flush_succeeds)
+
+
+if __name__ == '__main__':
+ UTXOCacheTracepointTest().main()