diff options
author | fanquake <fanquake@gmail.com> | 2022-02-20 11:25:56 +0000 |
---|---|---|
committer | fanquake <fanquake@gmail.com> | 2022-02-20 11:27:54 +0000 |
commit | 2b0735d183111a4e40c0d188bc91d0539faca5b7 (patch) | |
tree | be544ff3dc9c263a44c42c274f80be02c7dc03d5 /contrib/tracing | |
parent | 98b9d607a8c235bb44efc8d205d0bfba3bd2a3ab (diff) | |
parent | 799968e8b38833dc7fd7b6d488a66a14580ef674 (diff) |
Merge bitcoin/bitcoin#23907: tracing: utxocache tracepoints follow up for #22902
799968e8b38833dc7fd7b6d488a66a14580ef674 tracing: misc follow-ups to 22902 (0xb10c)
36a65847033540cf2203252c7baf42bc5ec97579 tracing: correctly scope utxocache:flush tracepoint (Arnab Sen)
Pull request description:
This PR is a follow-up to the [#22902](https://github.com/bitcoin/bitcoin/pull/22902).
Previously, the tracepoint `utxocache:flush` was called, even when it was not flushing. So, the tracepoint is now scoped to write only when coins cache to disk.
ACKs for top commit:
0xB10C:
ACK 799968e8b38833dc7fd7b6d488a66a14580ef674
Tree-SHA512: ebb096cbf991c551c81e4339821f10d9768c14cf3d8cb14d0ad851acff5980962228a1c746914c6aba3bdb27e8be53b33349c41efe8bab5542f639916e437b5f
Diffstat (limited to 'contrib/tracing')
-rw-r--r-- | contrib/tracing/README.md | 31 | ||||
-rwxr-xr-x | contrib/tracing/log_utxocache_flush.py | 21 | ||||
-rwxr-xr-x | contrib/tracing/log_utxos.bt | 2 |
3 files changed, 22 insertions, 32 deletions
diff --git a/contrib/tracing/README.md b/contrib/tracing/README.md index b71ce2f34b..a409a23ef8 100644 --- a/contrib/tracing/README.md +++ b/contrib/tracing/README.md @@ -237,7 +237,7 @@ Histogram of block connection times in milliseconds (ms). ### log_utxocache_flush.py -A BCC Python script to log the cache and index flushes. Based on the +A BCC Python script to log the UTXO cache flushes. Based on the `utxocache:flush` tracepoint. ```bash @@ -246,23 +246,10 @@ $ python3 contrib/tracing/log_utxocache_flush.py ./src/bitcoind ``` Logging utxocache flushes. Ctrl-C to end... -Duration (µs) Mode Coins Count Memory Usage Prune Full Flush -0 PERIODIC 28484 3929.87 kB False False -1 PERIODIC 28485 3930.00 kB False False -0 PERIODIC 28489 3930.51 kB False False -1 PERIODIC 28490 3930.64 kB False False -0 PERIODIC 28491 3930.77 kB False False -0 PERIODIC 28491 3930.77 kB False False -0 PERIODIC 28496 3931.41 kB False False -1 PERIODIC 28496 3931.41 kB False False -0 PERIODIC 28497 3931.54 kB False False -1 PERIODIC 28497 3931.54 kB False False -1 PERIODIC 28499 3931.79 kB False False -. -. -. -53788 ALWAYS 30076 4136.27 kB False False -7463 ALWAYS 0 245.84 kB False False +Duration (µs) Mode Coins Count Memory Usage Prune +730451 IF_NEEDED 22990 3323.54 kB True +637657 ALWAYS 122320 17124.80 kB False +81349 ALWAYS 0 1383.49 kB False ``` ### log_utxos.bt @@ -275,7 +262,13 @@ uncached from the UTXO set. Based on the `utxocache:add`, `utxocache:spend` and $ bpftrace contrib/tracing/log_utxos.bt ``` -It should produce an output similar to the following. +This should produce an output similar to the following. If you see bpftrace +warnings like `Lost 24 events`, the eBPF perf ring-buffer is filled faster +than it is being read. You can increase the ring-buffer size by setting the +ENV variable `BPFTRACE_PERF_RB_PAGES` (default 64) at a cost of higher +memory usage. See the [bpftrace reference guide] for more information. + +[bpftrace reference guide]: https://github.com/iovisor/bpftrace/blob/master/docs/reference_guide.md#98-bpftrace_perf_rb_pages ```bash Attaching 4 probes... diff --git a/contrib/tracing/log_utxocache_flush.py b/contrib/tracing/log_utxocache_flush.py index 7f26504e7b..8c073bea0d 100755 --- a/contrib/tracing/log_utxocache_flush.py +++ b/contrib/tracing/log_utxocache_flush.py @@ -16,14 +16,14 @@ from bcc import BPF, USDT # a sandboxed Linux kernel VM. program = """ # include <uapi/linux/ptrace.h> + struct data_t { u64 duration; u32 mode; u64 coins_count; u64 coins_mem_usage; - bool is_flush_prune; - bool is_full_flush; + bool is_flush_for_prune; }; // BPF perf buffer to push the data to user space. @@ -35,8 +35,7 @@ int trace_flush(struct pt_regs *ctx) { bpf_usdt_readarg(2, ctx, &data.mode); bpf_usdt_readarg(3, ctx, &data.coins_count); bpf_usdt_readarg(4, ctx, &data.coins_mem_usage); - bpf_usdt_readarg(5, ctx, &data.is_flush_prune); - bpf_usdt_readarg(5, ctx, &data.is_full_flush); + bpf_usdt_readarg(5, ctx, &data.is_flush_for_prune); flush.perf_submit(ctx, &data, sizeof(data)); return 0; } @@ -57,19 +56,17 @@ class Data(ctypes.Structure): ("mode", ctypes.c_uint32), ("coins_count", ctypes.c_uint64), ("coins_mem_usage", ctypes.c_uint64), - ("is_flush_prune", ctypes.c_bool), - ("is_full_flush", ctypes.c_bool) + ("is_flush_for_prune", ctypes.c_bool) ] def print_event(event): - print("%-15d %-10s %-15d %-15s %-8s %-8s" % ( + print("%-15d %-10s %-15d %-15s %-8s" % ( event.duration, FLUSH_MODES[event.mode], event.coins_count, "%.2f kB" % (event.coins_mem_usage/1000), - event.is_flush_prune, - event.is_full_flush + event.is_flush_for_prune )) @@ -90,9 +87,9 @@ def main(bitcoind_path): b["flush"].open_perf_buffer(handle_flush) print("Logging utxocache flushes. Ctrl-C to end...") - print("%-15s %-10s %-15s %-15s %-8s %-8s" % ("Duration (µs)", "Mode", - "Coins Count", "Memory Usage", - "Prune", "Full Flush")) + print("%-15s %-10s %-15s %-15s %-8s" % ("Duration (µs)", "Mode", + "Coins Count", "Memory Usage", + "Flush for Prune")) while True: try: diff --git a/contrib/tracing/log_utxos.bt b/contrib/tracing/log_utxos.bt index 0d47f3d62b..54d5010f82 100755 --- a/contrib/tracing/log_utxos.bt +++ b/contrib/tracing/log_utxos.bt @@ -7,7 +7,7 @@ bpftrace contrib/tracing/log_utxos.bt This script requires a 'bitcoind' binary compiled with eBPF support and the - 'utxochache' tracepoints. By default, it's assumed that 'bitcoind' is + 'utxocache' tracepoints. By default, it's assumed that 'bitcoind' is located in './src/bitcoind'. This can be modified in the script below. NOTE: requires bpftrace v0.12.0 or above. |