Skip to content

Commit

Permalink
X[tracing] added txid as bytes to tp param
Browse files Browse the repository at this point in the history
  • Loading branch information
@arnabsen1729
arnabsen1729 committed Sep 2, 2021
1 parent af3f958 commit ec39524
Show file tree
Hide file tree
Showing 5 changed files with 137 additions and 95 deletions.
40 changes: 20 additions & 20 deletions contrib/tracing/log_coins_flushed.py
View file
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
#!/usr/bin/env python3

import sys
import ctypes as ct
import ctypes
from bcc import BPF, USDT

""" Example script to log details about coins flushed by the Bitcoin client
Expand All @@ -16,9 +16,9 @@
struct data_t
{
long ts;
u64 duration;
u32 mode;
u64 coins;
u64 coins_count;
u64 coins_mem_usage;
bool is_flush_prune;
bool is_full_flush;
Expand All @@ -29,10 +29,9 @@
int trace_flush(struct pt_regs *ctx) {
struct data_t data = {};
bpf_usdt_readarg(1, ctx, &data.ts);
bpf_usdt_readarg(1, ctx, &data.duration);
bpf_usdt_readarg(2, ctx, &data.mode);
bpf_usdt_readarg(3, ctx, &data.coins);
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);
Expand All @@ -41,31 +40,31 @@
}
"""


FLUSH_MODES = [
'NONE',
'IF_NEEDED',
'PERIODIC',
'ALWAYS'
]


# define output data structure in Python
class Data(ct.Structure):
class Data(ctypes.Structure):
_fields_ = [
("ts", ct.c_long),
("mode", ct.c_uint32),
("coins", ct.c_uint64),
("coins_mem_usage", ct.c_uint64),
("is_flush_prune", ct.c_bool),
("is_full_flush", ct.c_bool)
("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("%-10d %-10s %-10d %-15s %-8s %-8s" % (
event.ts,
print("%-15d %-10s %-15d %-15s %-8s %-8s" % (
event.duration,
FLUSH_MODES[event.mode],
event.coins,
event.coins_count,
"%.2f kB" % (event.coins_mem_usage/1000),
event.is_flush_prune,
event.is_full_flush
Expand All @@ -85,13 +84,14 @@ def handle_flush(_, data, size):
""" Coins Flush handler.
Called each time coin caches and indexes are flushed."""
event = ct.cast(data, ct.POINTER(Data)).contents
event = ctypes.cast(data, ctypes.POINTER(Data)).contents
print_event(event)

b["flush"].open_perf_buffer(handle_flush)
print("Logging Coin flushes. Ctrl-C to end...")
print("%-10s %-10s %-10s %-15s %-8s %-8s" % ("Duration", "Mode",
"Coins", "Memory Usage", "Prune", "Full Flush"))
print("%-15s %-10s %-15s %-15s %-8s %-8s" % ("Duration (µs)", "Mode",
"Coins Count", "Memory Usage",
"Prune", "Full Flush"))

while True:
try:
Expand Down
104 changes: 66 additions & 38 deletions contrib/tracing/log_utxo_coins.py
View file
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
#!/usr/bin/env python3

import sys
import ctypes
from bcc import BPF, USDT

""" Example script to log details about add/spend/uncache coin events.
utilizing USDT probes and the utxo:coins_added, utxo:coins_spent,
utxo:coins_uncached tracepoint. """
utilizing USDT probes and the utxocache:add, utxocache:spent,
utxocache:uncache tracepoint."""

program = """
# include <uapi/linux/ptrace.h>
Expand All @@ -14,40 +15,43 @@
struct coin_data
{
u32 height;
u32 index;
char hash[MAX_HASH_SIZE];
u32 index;
u32 height;
long value;
u32 isCoinBase;
u64 usage;
u64 cachedCoinsCount;
bool isCoinBase;
};
BPF_PERF_OUTPUT(coins_added);
BPF_PERF_OUTPUT(coins_spent);
BPF_PERF_OUTPUT(coins_uncached);
BPF_PERF_OUTPUT(add);
BPF_PERF_OUTPUT(spent);
BPF_PERF_OUTPUT(uncache);
int trace_add_coin(struct pt_regs *ctx) {
struct coin_data data = {};
bpf_usdt_readarg_p(1, ctx, &data.hash, MAX_HASH_SIZE);
bpf_usdt_readarg(2, ctx, &data.index);
bpf_usdt_readarg(3, ctx, &data.height);
bpf_usdt_readarg(4, ctx, &data.value);
bpf_usdt_readarg(5, ctx, &data.isCoinBase);
bpf_usdt_readarg(6, ctx, &data.usage);
coins_added.perf_submit(ctx, &data, sizeof(data));
return 0;
struct coin_data data = {};
bpf_usdt_readarg_p(1, ctx, &data.hash, MAX_HASH_SIZE);
bpf_usdt_readarg(2, ctx, &data.index);
bpf_usdt_readarg(3, ctx, &data.height);
bpf_usdt_readarg(4, ctx, &data.value);
bpf_usdt_readarg(5, ctx, &data.isCoinBase);
bpf_usdt_readarg(6, ctx, &data.usage);
bpf_usdt_readarg(7, ctx, &data.cachedCoinsCount);
add.perf_submit(ctx, &data, sizeof(data));
return 0;
}
int trace_spend_coin(struct pt_regs *ctx) {
struct coin_data data = {};
bpf_usdt_readarg_p(1, ctx, &data.hash, MAX_HASH_SIZE);
bpf_usdt_readarg(2, ctx, &data.index);
bpf_usdt_readarg(3, ctx, &data.height);
bpf_usdt_readarg(4, ctx, &data.value);
bpf_usdt_readarg(5, ctx, &data.isCoinBase);
bpf_usdt_readarg(6, ctx, &data.usage);
coins_spent.perf_submit(ctx, &data, sizeof(data));
return 0;
struct coin_data data = {};
bpf_usdt_readarg_p(1, ctx, &data.hash, MAX_HASH_SIZE);
bpf_usdt_readarg(2, ctx, &data.index);
bpf_usdt_readarg(3, ctx, &data.height);
bpf_usdt_readarg(4, ctx, &data.value);
bpf_usdt_readarg(5, ctx, &data.isCoinBase);
bpf_usdt_readarg(6, ctx, &data.usage);
bpf_usdt_readarg(7, ctx, &data.cachedCoinsCount);
spent.perf_submit(ctx, &data, sizeof(data));
return 0;
}
int trace_uncached_coin(struct pt_regs *ctx) {
Expand All @@ -58,16 +62,33 @@
bpf_usdt_readarg(4, ctx, &data.value);
bpf_usdt_readarg(5, ctx, &data.isCoinBase);
bpf_usdt_readarg(6, ctx, &data.usage);
coins_uncached.perf_submit(ctx, &data, sizeof(data));
bpf_usdt_readarg(7, ctx, &data.cachedCoinsCount);
uncache.perf_submit(ctx, &data, sizeof(data));
return 0;
}
"""


class Data(ctypes.Structure):
_fields_ = [
("hash", ctypes.c_char * 64),
("index", ctypes.c_uint32),
("height", ctypes.c_uint32),
("value", ctypes.c_uint64),
("usage", ctypes.c_uint64),
("cachedCoinsCount", ctypes.c_uint64),
("isCoinBase", ctypes.c_bool),
]


def print_event(event, action):
# print(event.hash.decode('ASCII'), action, event.height, event.value, "YES" if event.isCoinBase else "NO", event.usage)
print("%-70s %-10s %-10d %-15d %-10s %-10d" %
(f"{event.hash.decode('ASCII')}:{str(event.index)}", action, event.height, event.value, "YES" if event.isCoinBase else "NO", event.usage))
print("%-70s %-10s %-10d %-15d %-10s %-15d %d" %
(f"{event.hash.decode('ASCII')}:{str(event.index)}",
action, event.height,
event.value,
"YES" if event.isCoinBase else "NO",
event.usage,
event.cachedCoinsCount))


def main(bitcoind_path):
Expand All @@ -82,24 +103,31 @@ def main(bitcoind_path):
b = BPF(text=program, usdt_contexts=[bitcoind_with_usdts])

def handle_coins_added(_, data, size):
event = b["coins_added"].event(data)
event = ctypes.cast(data, ctypes.POINTER(Data)).contents
print_event(event, "Add")

def handle_coins_spent(_, data, size):
event = b["coins_spent"].event(data)
event = ctypes.cast(data, ctypes.POINTER(Data)).contents
print_event(event, "Spent")

def handle_coins_uncached(_, data, size):
event = b["coins_uncached"].event(data)
event = ctypes.cast(data, ctypes.POINTER(Data)).contents
print_event(event, "Uncache")

b["coins_added"].open_perf_buffer(handle_coins_added)
b["coins_spent"].open_perf_buffer(handle_coins_spent)
b["coins_uncached"].open_perf_buffer(handle_coins_uncached)
b["add"].open_perf_buffer(handle_coins_added)
b["spent"].open_perf_buffer(handle_coins_spent)
b["uncache"].open_perf_buffer(handle_coins_uncached)

print("Logging Add, Spend and Uncache in the UTXO set. Ctrl-C to end...")
print("%-70s %-10s %-10s %-15s %-10s %s" %
("txHash", "Action", "Height", "Satoshis", "Coin Base", "Usage"))
print("%-70s %-10s %-10s %-15s %-10s %-15s %s" %
("Outpoint",
"Action",
"Height",
"Value",
"Coinbase",
"Memory Usage",
"Cached Coins"))

while True:
try:
b.perf_buffer_poll()
Expand Down
51 changes: 30 additions & 21 deletions doc/tracing.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -117,50 +117,59 @@ details.

### Context `utxocache`

#### Tracepoint `utxocache:coins_flushed`
#### Tracepoint `utxocache:flush`

Is called *after* the caches and indexes are flushed depending on the mode
`CChainState::FlushStateToDisk` called with.
`CChainState::FlushStateToDisk` is called with.

Arguments passed:
1. Time in microseconds as `int64`
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. Size of the cache in bytes 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`

### Context `utxo`

#### Tracepoint `utxo:coins_added`
#### Tracepoint `utxocache:add`

It is called when a new coin is added to the UTXO cache.

Arguments passed:
1. Block height the coin was added to the UTXO-set as `int32`
2. Value of the coin as `int64`
3. If the coin is a coinbase as `uint32`
4. Cached coins usage as `uint64`
1. Transaction ID (hash) as `pointer to C-style String` (64 characters)
2. The 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 `uint`
6. Cached coins usage as `uint64`
7. Transaction hash as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)

#### Tracepoint `utxo:coins_spent`
#### Tracepoint `utxocache:spent`

It is called when a coin is spent from the UTXO cache.

Arguments passed:
1. Block height the coin was spent , as `int32`
2. Value of the coin as `int64`
3. If the coin is a coinbase as `uint32`
4. Cached coins usage as `uint64`
1. Transaction ID (hash) as `pointer to C-style String` (64 characters)
2. The 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 `uint`
6. Cached coins usage as `uint64`
7. Transaction hash as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)

#### Tracepoint `utxo:coins_uncached`
#### Tracepoint `utxocache:uncache`

It is called when the UTXO with the given outpoint is removed from the cache,
if it is not modified.

Arguments passed:
1. Block height the coin was uncached, as `int32`
2. Value of the coin as `int64`
3. If the coin is a coinbase as `uint32`
4. Cached coins usage as `uint64`
1. Transaction ID (hash) as `pointer to C-style String` (64 characters)
2. The output index as `uint32`
3. Block height the coin was uncached, as `uint32`
4. Value of the coin as `int64`
5. If the coin is a coinbase as `uint`
6. Cached coins usage as `uint64`
7. Transaction hash as `pointer to unsigned chars` (i.e. 32 bytes in little-endian)

## Adding tracepoints to Bitcoin Core

Expand Down
25 changes: 15 additions & 10 deletions src/coins.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -96,13 +96,15 @@ void CCoinsViewCache::AddCoin(const COutPoint &outpoint, Coin&& coin, bool possi
it->second.coin = std::move(coin);
it->second.flags |= CCoinsCacheEntry::DIRTY | (fresh ? CCoinsCacheEntry::FRESH : 0);
cachedCoinsUsage += it->second.coin.DynamicMemoryUsage();
TRACE6(utxocache, add,
TRACE8(utxocache, add,
outpoint.hash.ToString().c_str(),
(uint32_t)outpoint.n,
(uint32_t)coin.nHeight,
(int64_t)coin.out.nValue,
(uint)coin.fCoinBase,
(uint64_t)cachedCoinsUsage
(uint64_t)cachedCoinsUsage,
(uint64_t)cacheCoins.size(),
(bool)coin.IsCoinBase(),
outpoint.hash.data()
);
}

Expand Down Expand Up @@ -130,13 +132,15 @@ bool CCoinsViewCache::SpendCoin(const COutPoint &outpoint, Coin* moveout) {
if (it == cacheCoins.end()) return false;
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();

TRACE6(utxocache, spent,
TRACE8(utxocache, spent,
outpoint.hash.ToString().c_str(),
(uint32_t)outpoint.n,
(uint32_t)it->second.coin.nHeight,
(int64_t)it->second.coin.out.nValue,
(uint)it->second.coin.fCoinBase,
(uint64_t)cachedCoinsUsage
(uint64_t)cachedCoinsUsage,
(uint64_t)cacheCoins.size(),
(bool)it->second.coin.IsCoinBase(),
outpoint.hash.data()
);

if (moveout) {
Expand Down Expand Up @@ -248,17 +252,18 @@ bool CCoinsViewCache::Flush() {
void CCoinsViewCache::Uncache(const COutPoint& hash)
{
CCoinsMap::iterator it = cacheCoins.find(hash);

if (it != cacheCoins.end() && it->second.flags == 0) {
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();

TRACE6(utxocache, uncache,
TRACE8(utxocache, uncache,
hash.hash.ToString().c_str(),
(uint32_t)hash.n,
(uint32_t)it->second.coin.nHeight,
(int64_t)it->second.coin.out.nValue,
(uint)it->second.coin.fCoinBase,
(uint64_t)cachedCoinsUsage
(uint64_t)cachedCoinsUsage,
(uint64_t)cacheCoins.size(),
(bool)it->second.coin.IsCoinBase(),
hash.hash.data()
);

cacheCoins.erase(it);
Expand Down
Loading

0 comments on commit ec39524

Please sign in to comment.