mirror of
https://github.com/dashpay/dash.git
synced 2024-12-25 20:12:57 +01:00
merge bitcoin#22902: utxocache tracepoints
This commit is contained in:
parent
644a47ef9a
commit
6cc596b99a
@ -234,3 +234,62 @@ Histogram of block connection times in milliseconds (ms).
|
|||||||
[16, 32) 9 | |
|
[16, 32) 9 | |
|
||||||
[32, 64) 4 | |
|
[32, 64) 4 | |
|
||||||
```
|
```
|
||||||
|
|
||||||
|
### log_utxocache_flush.py
|
||||||
|
|
||||||
|
A BCC Python script to log the cache and index flushes. Based on the
|
||||||
|
`utxocache:flush` tracepoint.
|
||||||
|
|
||||||
|
```bash
|
||||||
|
$ python3 contrib/tracing/log_utxocache_flush.py ./src/dashd
|
||||||
|
```
|
||||||
|
|
||||||
|
```
|
||||||
|
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
|
||||||
|
```
|
||||||
|
|
||||||
|
### log_utxos.bt
|
||||||
|
|
||||||
|
A `bpftrace` script to log information about the coins that are added, spent, or
|
||||||
|
uncached from the UTXO set. Based on the `utxocache:add`, `utxocache:spend` and
|
||||||
|
`utxocache:uncache` tracepoints.
|
||||||
|
|
||||||
|
```bash
|
||||||
|
$ bpftrace contrib/tracing/log_utxos.bt
|
||||||
|
```
|
||||||
|
|
||||||
|
It should produce an output similar to the following.
|
||||||
|
|
||||||
|
```bash
|
||||||
|
Attaching 4 probes...
|
||||||
|
OP Outpoint Value Height Coinbase
|
||||||
|
Added 6ba9ad857e1ef2eb2a2c94f06813c414c7ab273e3d6bd7ad64e000315a887e7c:1 10000 2094512 No
|
||||||
|
Spent fa7dc4db56637a151f6649d8f26732956d1c5424c82aae400a83d02b2cc2c87b:0 182264897 2094512 No
|
||||||
|
Added eeb2f099b1af6a2a12e6ddd2eeb16fc5968582241d7f08ba202d28b60ac264c7:0 10000 2094512 No
|
||||||
|
Added eeb2f099b1af6a2a12e6ddd2eeb16fc5968582241d7f08ba202d28b60ac264c7:1 182254756 2094512 No
|
||||||
|
Added a0c7f4ec9cccef2d89672a624a4e6c8237a17572efdd4679eea9e9ee70d2db04:0 10072679 2094513 Yes
|
||||||
|
Spent 25e0df5cc1aeb1b78e6056bf403e5e8b7e41f138060ca0a50a50134df0549a5e:2 540 2094508 No
|
||||||
|
Spent 42f383c04e09c26a2378272ec33aa0c1bf4883ca5ab739e8b7e06be5a5787d61:1 3848399 2007724 No
|
||||||
|
Added f85e3b4b89270863a389395cc9a4123e417ab19384cef96533c6649abd6b0561:0 3788399 2094513 No
|
||||||
|
Added f85e3b4b89270863a389395cc9a4123e417ab19384cef96533c6649abd6b0561:2 540 2094513 No
|
||||||
|
Spent a05880b8c77971ed0b9f73062c7c4cdb0ff3856ab14cbf8bc481ed571cd34b83:1 5591281046 2094511 No
|
||||||
|
Added eb689865f7d957938978d6207918748f74e6aa074f47874724327089445b0960:0 5589696005 2094513 No
|
||||||
|
Added eb689865f7d957938978d6207918748f74e6aa074f47874724327089445b0960:1 1565556 2094513 No
|
||||||
|
```
|
||||||
|
107
contrib/tracing/log_utxocache_flush.py
Executable file
107
contrib/tracing/log_utxocache_flush.py
Executable file
@ -0,0 +1,107 @@
|
|||||||
|
#!/usr/bin/env python3
|
||||||
|
|
||||||
|
import sys
|
||||||
|
import ctypes
|
||||||
|
from bcc import BPF, USDT
|
||||||
|
|
||||||
|
"""Example logging Dash Core utxo set cache flushes utilizing
|
||||||
|
the utxocache:flush tracepoint."""
|
||||||
|
|
||||||
|
# USAGE: ./contrib/tracing/log_utxocache_flush.py path/to/dashd
|
||||||
|
|
||||||
|
# BCC: The C program to be compiled to an eBPF program (by BCC) and loaded into
|
||||||
|
# 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;
|
||||||
|
};
|
||||||
|
|
||||||
|
// BPF perf buffer to push the data to user space.
|
||||||
|
BPF_PERF_OUTPUT(flush);
|
||||||
|
|
||||||
|
int trace_flush(struct pt_regs *ctx) {
|
||||||
|
struct data_t data = {};
|
||||||
|
bpf_usdt_readarg(1, ctx, &data.duration);
|
||||||
|
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);
|
||||||
|
flush.perf_submit(ctx, &data, sizeof(data));
|
||||||
|
return 0;
|
||||||
|
}
|
||||||
|
"""
|
||||||
|
|
||||||
|
FLUSH_MODES = [
|
||||||
|
'NONE',
|
||||||
|
'IF_NEEDED',
|
||||||
|
'PERIODIC',
|
||||||
|
'ALWAYS'
|
||||||
|
]
|
||||||
|
|
||||||
|
|
||||||
|
class Data(ctypes.Structure):
|
||||||
|
# define output data structure corresponding to struct data_t
|
||||||
|
_fields_ = [
|
||||||
|
("duration", ctypes.c_uint64),
|
||||||
|
("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)
|
||||||
|
]
|
||||||
|
|
||||||
|
|
||||||
|
def print_event(event):
|
||||||
|
print("%-15d %-10s %-15d %-15s %-8s %-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
|
||||||
|
))
|
||||||
|
|
||||||
|
|
||||||
|
def main(bitcoind_path):
|
||||||
|
bitcoind_with_usdts = USDT(path=str(bitcoind_path))
|
||||||
|
|
||||||
|
# attaching the trace functions defined in the BPF program
|
||||||
|
# to the tracepoints
|
||||||
|
bitcoind_with_usdts.enable_probe(
|
||||||
|
probe="flush", fn_name="trace_flush")
|
||||||
|
b = BPF(text=program, usdt_contexts=[bitcoind_with_usdts])
|
||||||
|
|
||||||
|
def handle_flush(_, data, size):
|
||||||
|
""" Coins Flush handler.
|
||||||
|
Called each time coin caches and indexes are flushed."""
|
||||||
|
event = ctypes.cast(data, ctypes.POINTER(Data)).contents
|
||||||
|
print_event(event)
|
||||||
|
|
||||||
|
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"))
|
||||||
|
|
||||||
|
while True:
|
||||||
|
try:
|
||||||
|
b.perf_buffer_poll()
|
||||||
|
except KeyboardInterrupt:
|
||||||
|
exit(0)
|
||||||
|
|
||||||
|
|
||||||
|
if __name__ == "__main__":
|
||||||
|
if len(sys.argv) < 2:
|
||||||
|
print("USAGE: ", sys.argv[0], "path/to/dashd")
|
||||||
|
exit(1)
|
||||||
|
|
||||||
|
path = sys.argv[1]
|
||||||
|
main(path)
|
86
contrib/tracing/log_utxos.bt
Executable file
86
contrib/tracing/log_utxos.bt
Executable file
@ -0,0 +1,86 @@
|
|||||||
|
#!/usr/bin/env bpftrace
|
||||||
|
|
||||||
|
/*
|
||||||
|
|
||||||
|
USAGE:
|
||||||
|
|
||||||
|
bpftrace contrib/tracing/log_utxos.bt
|
||||||
|
|
||||||
|
This script requires a 'dashd' binary compiled with eBPF support and the
|
||||||
|
'utxochache' tracepoints. By default, it's assumed that 'dashd' is
|
||||||
|
located in './src/dashd'. This can be modified in the script below.
|
||||||
|
|
||||||
|
NOTE: requires bpftrace v0.12.0 or above.
|
||||||
|
*/
|
||||||
|
|
||||||
|
BEGIN
|
||||||
|
{
|
||||||
|
printf("%-7s %-71s %16s %7s %8s\n",
|
||||||
|
"OP", "Outpoint", "Value", "Height", "Coinbase");
|
||||||
|
}
|
||||||
|
|
||||||
|
/*
|
||||||
|
Attaches to the 'utxocache:add' tracepoint and prints additions to the UTXO set cache.
|
||||||
|
*/
|
||||||
|
usdt:./src/dashd:utxocache:add
|
||||||
|
{
|
||||||
|
$txid = arg0;
|
||||||
|
$index = (uint32)arg1;
|
||||||
|
$height = (uint32)arg2;
|
||||||
|
$value = (int64)arg3;
|
||||||
|
$isCoinbase = arg4;
|
||||||
|
|
||||||
|
printf("Added ");
|
||||||
|
$p = $txid + 31;
|
||||||
|
unroll(32) {
|
||||||
|
$b = *(uint8*)$p;
|
||||||
|
printf("%02x", $b);
|
||||||
|
$p-=1;
|
||||||
|
}
|
||||||
|
|
||||||
|
printf(":%-6d %16ld %7d %s\n", $index, $value, $height, ($isCoinbase ? "Yes" : "No" ));
|
||||||
|
}
|
||||||
|
|
||||||
|
/*
|
||||||
|
Attaches to the 'utxocache:spent' tracepoint and prints spents from the UTXO set cache.
|
||||||
|
*/
|
||||||
|
usdt:./src/dashd:utxocache:spent
|
||||||
|
{
|
||||||
|
$txid = arg0;
|
||||||
|
$index = (uint32)arg1;
|
||||||
|
$height = (uint32)arg2;
|
||||||
|
$value = (int64)arg3;
|
||||||
|
$isCoinbase = arg4;
|
||||||
|
|
||||||
|
printf("Spent ");
|
||||||
|
$p = $txid + 31;
|
||||||
|
unroll(32) {
|
||||||
|
$b = *(uint8*)$p;
|
||||||
|
printf("%02x", $b);
|
||||||
|
$p-=1;
|
||||||
|
}
|
||||||
|
|
||||||
|
printf(":%-6d %16ld %7d %s\n", $index, $value, $height, ($isCoinbase ? "Yes" : "No" ));
|
||||||
|
}
|
||||||
|
|
||||||
|
/*
|
||||||
|
Attaches to the 'utxocache:uncache' tracepoint and uncache UTXOs from the UTXO set cache.
|
||||||
|
*/
|
||||||
|
usdt:./src/dashd:utxocache:uncache
|
||||||
|
{
|
||||||
|
$txid = arg0;
|
||||||
|
$index = (uint32)arg1;
|
||||||
|
$height = (uint32)arg2;
|
||||||
|
$value = (int64)arg3;
|
||||||
|
$isCoinbase = arg4;
|
||||||
|
|
||||||
|
printf("Uncache ");
|
||||||
|
$p = $txid + 31;
|
||||||
|
unroll(32) {
|
||||||
|
$b = *(uint8*)$p;
|
||||||
|
printf("%02x", $b);
|
||||||
|
$p-=1;
|
||||||
|
}
|
||||||
|
|
||||||
|
printf(":%-6d %16ld %7d %s\n", $index, $value, $height, ($isCoinbase ? "Yes" : "No" ));
|
||||||
|
}
|
@ -108,6 +108,55 @@ Arguments passed:
|
|||||||
5. SigOps in the Block (excluding coinbase SigOps) `uint64`
|
5. SigOps in the Block (excluding coinbase SigOps) `uint64`
|
||||||
6. Time it took to connect the Block in microseconds (µs) as `uint64`
|
6. Time it took to connect the Block in microseconds (µs) as `uint64`
|
||||||
|
|
||||||
|
### Context `utxocache`
|
||||||
|
|
||||||
|
#### Tracepoint `utxocache:flush`
|
||||||
|
|
||||||
|
Is called *after* the caches and indexes are flushed depending on the mode
|
||||||
|
`CChainState::FlushStateToDisk` is called with.
|
||||||
|
|
||||||
|
Arguments passed:
|
||||||
|
1. Duration in microseconds as `int64`
|
||||||
|
2. Flush state mode as `uint32`. It's an enumerator class with values `0`
|
||||||
|
(`NONE`), `1` (`IF_NEEDED`), `2` (`PERIODIC`), `3` (`ALWAYS`)
|
||||||
|
3. Number of coins flushed as `uint64`
|
||||||
|
4. Memory usage in bytes as `uint64`
|
||||||
|
5. If the flush was pruned as `bool`
|
||||||
|
6. If it was full flush as `bool`
|
||||||
|
|
||||||
|
#### Tracepoint `utxocache:add`
|
||||||
|
|
||||||
|
It is called when a new coin is added to the UTXO cache.
|
||||||
|
|
||||||
|
Arguments passed:
|
||||||
|
1. Transaction ID (hash) as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)
|
||||||
|
2. Output index as `uint32`
|
||||||
|
3. Block height the coin was added to the UTXO-set as `uint32`
|
||||||
|
4. Value of the coin as `int64`
|
||||||
|
5. If the coin is a coinbase as `bool`
|
||||||
|
|
||||||
|
#### Tracepoint `utxocache:spent`
|
||||||
|
|
||||||
|
It is called when a coin is spent from the UTXO cache.
|
||||||
|
|
||||||
|
Arguments passed:
|
||||||
|
1. Transaction ID (hash) as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)
|
||||||
|
2. Output index as `uint32`
|
||||||
|
3. Block height the coin was spent, as `uint32`
|
||||||
|
4. Value of the coin as `int64`
|
||||||
|
5. If the coin is a coinbase as `bool`
|
||||||
|
|
||||||
|
#### Tracepoint `utxocache:uncache`
|
||||||
|
|
||||||
|
It is called when the UTXO with the given outpoint is removed from the cache.
|
||||||
|
|
||||||
|
Arguments passed:
|
||||||
|
1. Transaction ID (hash) as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)
|
||||||
|
2. Output index as `uint32`
|
||||||
|
3. Block height the coin was uncached, as `uint32`
|
||||||
|
4. Value of the coin as `int64`
|
||||||
|
. If the coin is a coinbase as `bool`
|
||||||
|
|
||||||
## Adding tracepoints to Dash Core
|
## Adding tracepoints to Dash Core
|
||||||
|
|
||||||
To add a new tracepoint, `#include <util/trace.h>` in the compilation unit where
|
To add a new tracepoint, `#include <util/trace.h>` in the compilation unit where
|
||||||
|
@ -7,6 +7,7 @@
|
|||||||
#include <consensus/consensus.h>
|
#include <consensus/consensus.h>
|
||||||
#include <logging.h>
|
#include <logging.h>
|
||||||
#include <random.h>
|
#include <random.h>
|
||||||
|
#include <util/trace.h>
|
||||||
#include <version.h>
|
#include <version.h>
|
||||||
|
|
||||||
bool CCoinsView::GetCoin(const COutPoint &outpoint, Coin &coin) const { return false; }
|
bool CCoinsView::GetCoin(const COutPoint &outpoint, Coin &coin) const { return false; }
|
||||||
@ -98,6 +99,12 @@ void CCoinsViewCache::AddCoin(const COutPoint &outpoint, Coin&& coin, bool possi
|
|||||||
it->second.coin = std::move(coin);
|
it->second.coin = std::move(coin);
|
||||||
it->second.flags |= CCoinsCacheEntry::DIRTY | (fresh ? CCoinsCacheEntry::FRESH : 0);
|
it->second.flags |= CCoinsCacheEntry::DIRTY | (fresh ? CCoinsCacheEntry::FRESH : 0);
|
||||||
cachedCoinsUsage += it->second.coin.DynamicMemoryUsage();
|
cachedCoinsUsage += it->second.coin.DynamicMemoryUsage();
|
||||||
|
TRACE5(utxocache, add,
|
||||||
|
outpoint.hash.data(),
|
||||||
|
(uint32_t)outpoint.n,
|
||||||
|
(uint32_t)coin.nHeight,
|
||||||
|
(int64_t)coin.out.nValue,
|
||||||
|
(bool)coin.IsCoinBase());
|
||||||
}
|
}
|
||||||
|
|
||||||
void CCoinsViewCache::EmplaceCoinInternalDANGER(COutPoint&& outpoint, Coin&& coin) {
|
void CCoinsViewCache::EmplaceCoinInternalDANGER(COutPoint&& outpoint, Coin&& coin) {
|
||||||
@ -123,6 +130,12 @@ bool CCoinsViewCache::SpendCoin(const COutPoint &outpoint, Coin* moveout) {
|
|||||||
CCoinsMap::iterator it = FetchCoin(outpoint);
|
CCoinsMap::iterator it = FetchCoin(outpoint);
|
||||||
if (it == cacheCoins.end()) return false;
|
if (it == cacheCoins.end()) return false;
|
||||||
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
|
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
|
||||||
|
TRACE5(utxocache, spent,
|
||||||
|
outpoint.hash.data(),
|
||||||
|
(uint32_t)outpoint.n,
|
||||||
|
(uint32_t)it->second.coin.nHeight,
|
||||||
|
(int64_t)it->second.coin.out.nValue,
|
||||||
|
(bool)it->second.coin.IsCoinBase());
|
||||||
if (moveout) {
|
if (moveout) {
|
||||||
*moveout = std::move(it->second.coin);
|
*moveout = std::move(it->second.coin);
|
||||||
}
|
}
|
||||||
@ -273,6 +286,12 @@ void CCoinsViewCache::Uncache(const COutPoint& hash)
|
|||||||
CCoinsMap::iterator it = cacheCoins.find(hash);
|
CCoinsMap::iterator it = cacheCoins.find(hash);
|
||||||
if (it != cacheCoins.end() && it->second.flags == 0) {
|
if (it != cacheCoins.end() && it->second.flags == 0) {
|
||||||
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
|
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
|
||||||
|
TRACE5(utxocache, uncache,
|
||||||
|
hash.hash.data(),
|
||||||
|
(uint32_t)hash.n,
|
||||||
|
(uint32_t)it->second.coin.nHeight,
|
||||||
|
(int64_t)it->second.coin.out.nValue,
|
||||||
|
(bool)it->second.coin.IsCoinBase());
|
||||||
cacheCoins.erase(it);
|
cacheCoins.erase(it);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
@ -2472,6 +2472,13 @@ bool CChainState::FlushStateToDisk(
|
|||||||
nLastFlush = nNow;
|
nLastFlush = nNow;
|
||||||
full_flush_completed = true;
|
full_flush_completed = true;
|
||||||
}
|
}
|
||||||
|
TRACE6(utxocache, flush,
|
||||||
|
(int64_t)(GetTimeMicros() - nNow.count()), // in microseconds (µs)
|
||||||
|
(u_int32_t)mode,
|
||||||
|
(u_int64_t)coins_count,
|
||||||
|
(u_int64_t)coins_mem_usage,
|
||||||
|
(bool)fFlushForPrune,
|
||||||
|
(bool)fDoFullFlush);
|
||||||
}
|
}
|
||||||
if (full_flush_completed) {
|
if (full_flush_completed) {
|
||||||
// Update best block in wallet (so we can detect restored wallets).
|
// Update best block in wallet (so we can detect restored wallets).
|
||||||
|
Loading…
Reference in New Issue
Block a user