Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: utxocache tracepoints #22902

Merged
merged 2 commits into from
Nov 29, 2021

Conversation

arnabsen1729
Copy link
Contributor

This PR adds some of the UTXO set cache tracepoints proposed in #20981 (comment). The first tracepoints were added in #22006.

tracepoint description
utxocache:flush Is called after the caches and indexes are flushed
utxocache:add when a new coin is added to the UTXO cache
utxocache:spent when a coin is spent
utxocache:uncache when coin is removed from the UTXO cache

The tracepoints are further documented in docs/tracing.md and the usage is shown via the two newly added example scripts in contrib/tracing/.

@0xB10C
Copy link
Contributor

0xB10C commented Sep 6, 2021

Concept ACK.

@arnabsen1729 is working on this as part of his summerofbitcoin.org project. I've mentored him along the way. Some earlier review is in 0xB10C#1.

I suspect hooking into the add and spend tracepoints during IBD could have a noticeable performance impact. I'll test this. If is is the case, then it should be documented. Not hooking into the tracepoints shouldn't have any performance impact.

@@ -2120,6 +2120,13 @@ bool CChainState::FlushStateToDisk(
nLastFlush = nNow;
full_flush_completed = true;
}
TRACE6(utxocache, flush,
(int64_t)(GetTimeMicros() - nNow.count()), // in microseconds (µs)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what's the purpose of this argument?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The purpose was to get the duration of the flush, this value can be used for benchmarking purposes.

The nNow was declared here:

const auto nNow = GetTime<std::chrono::microseconds>();

src/coins.cpp Outdated
@@ -95,6 +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();
TRACE8(utxocache, add,
outpoint.hash.ToString().c_str(),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do we need the hash string here (and the ones below)? we should avoid doing non-negligible computations in traces.

Copy link
Contributor

@0xB10C 0xB10C Sep 6, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We need if we want to support the current versions of bpftrace as it can't print binary data in hex (or at all really).

related discussion #22006 (comment)

might be worth thinking about adding support for this in bpftrace rather than this work around here

Copy link
Contributor

@0xB10C 0xB10C Sep 6, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree that outpoint.hash.ToString().c_str() here is called a lot more than the hash.data().toString().c_str() in the connect_block tracepoint. This could hurt performance. Might need to drop this.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How about only using the first 64bit of the hash: outpoint.hash.GetUint64(0). This should be very fast and maybe unique enough, at least for the purpose of tracing

Copy link
Contributor

@0xB10C 0xB10C Sep 9, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We already pass outpoint.hash.data() as the last argument, that's not the issue. The issue here is the ToString() part which might be to expensive in such a frequently called function while being only a work around for bpftrace not supporting hex-formatting.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just came across bpftrace/bpftrace#659 (comment). We don't need to use the built-in hex-formatting as it's quite simple just printf("%02x") each byte of the txid in an unroll () {...}. This even allows us to print the txids in big-endian (the block-explorer format).

  $p = $txid + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p-=1;
  }

This means we can drop the outpoint.hash.ToString().c_str() from the tracepoints added here and use the outpoint.hash.data() as the first argument.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice, I was trying to use unroll like this for printing data in bpftrace but could never figure it out. I was never able to do it based on a length argument, probably because it wasn't a literal. This case works fine though since we know the length of the hash.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We already pass outpoint.hash.data() as the last argument, that's not the issue. The issue here is the ToString() part which might be to expensive in such a frequently called function while being only a work around for bpftrace not supporting hex-formatting.

I agree here. Let's remove this ToString argument. It's too much overhead to allocate, construct, deallocate a string here every time even if the tracepoint is disabled.

@DrahtBot
Copy link
Contributor

DrahtBot commented Sep 7, 2021

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #9384 (CCoinsViewCache code cleanup & deduplication by ryanofsky)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

@practicalswift
Copy link
Contributor

Concept ACK

1 similar comment
@theStack
Copy link
Contributor

theStack commented Sep 8, 2021

Concept ACK

maflcko pushed a commit to maflcko/bitcoin-core-with-ci that referenced this pull request Sep 9, 2021
15b8ba5 [tracing] tracepoints to utxocache add, spent and uncache (Arnab Sen)
56f0a04 [tracing] tracepoint for utxocache flushes (Arnab Sen)

Pull request description:

  This PR adds some of the UTXO set cache tracepoints proposed in bitcoin/bitcoin#20981 (comment). The first tracepoints were added in bitcoin#22006.

  tracepoint | description
  -- | --
  `utxocache:flush` | Is called after the caches and indexes are flushed
  `utxocache:add` | when a new coin is added to the UTXO cache
  `utxocache:spent` | when a coin is spent
  `utxocache:uncache` | when coin is removed from the UTXO cache

  The tracepoints are further documented in `docs/tracing.md` and the usage is shown via the two newly added example scripts in `contrib/tracing/`.

Top commit has no ACKs.

Tree-SHA512: 53ba6c2811c7fed08aa608a888bff83214e754b0f50621e83e4f81e95bc22d21f7f956096d12858d8e85240aa226431845995682eaaf55e93016c5b8f4c9282b
maflcko pushed a commit to maflcko/bitcoin-core-with-ci that referenced this pull request Sep 9, 2021
15b8ba5 [tracing] tracepoints to utxocache add, spent and uncache (Arnab Sen)
56f0a04 [tracing] tracepoint for utxocache flushes (Arnab Sen)

Pull request description:

  This PR adds some of the UTXO set cache tracepoints proposed in bitcoin/bitcoin#20981 (comment). The first tracepoints were added in bitcoin#22006.

  tracepoint | description
  -- | --
  `utxocache:flush` | Is called after the caches and indexes are flushed
  `utxocache:add` | when a new coin is added to the UTXO cache
  `utxocache:spent` | when a coin is spent
  `utxocache:uncache` | when coin is removed from the UTXO cache

  The tracepoints are further documented in `docs/tracing.md` and the usage is shown via the two newly added example scripts in `contrib/tracing/`.

Top commit has no ACKs.

Tree-SHA512: 53ba6c2811c7fed08aa608a888bff83214e754b0f50621e83e4f81e95bc22d21f7f956096d12858d8e85240aa226431845995682eaaf55e93016c5b8f4c9282b
@0xB10C
Copy link
Contributor

0xB10C commented Sep 10, 2021

My benchmarks (4x reindex-chainstate till block 500000 for both the mergebase 92aad53 and 15b8ba5) show that this PR increases time spent in ConnectBlock by about 3.4%. This is without hooking into the tracepoints.

image

As discussed in #22902 (comment) we can drop the first argument of the add, spent, and uncache tracepoints which should improve the performance. Will re-benchmark then.

@0xB10C
Copy link
Contributor

0xB10C commented Sep 11, 2021

Did some more profiling on a node in IBD running with this PR (15b8ba5) to make sure the ToString() is really the issue here.

In CCoinsViewCache::SpendCoin we spend more than half of the time in ToString().
image

In CCoinsViewCache::AddCoin we spend a lot less time in ToString() compared to CCoinsViewCache::SpendCoin, but still significant time.
image

(please ignore the bitcoind-22902-mergebase binary name shown here. It's not the mergebase, the binary is build from 15b8ba5)

@laanwj
Copy link
Member

laanwj commented Oct 1, 2021

I think in general good advice is to pass binary/raw data into the trace functions directly. Don't spent effort formatting, you can do this on the other side (and only when necessary, just before presentation to the user).

0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Oct 18, 2021
This tracepoint was introduced in bitcoin#22006. The first argument was the
hash of the connected block as a pointer to a C-like String. The last
argument passed the hash of the connected block as pointer to 32
bytes. The hash was passed both as pointer to a string and to bytes
to allow `bpftrace` scripts to print the String. It was (incorrectly)
assumed that `bpftrace` is not able to hex-format and print the block
hash given only the hash bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash it can be printed in in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p-=1;
  }
```

See also: bitcoin#22902 (comment)

This is a breaking change to the connect_block tracepoint API, however
there exist no release including the tracepoint yet.
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Oct 18, 2021
This tracepoint was introduced in bitcoin#22006. The first argument was the
hash of the connected block as a pointer to a C-like String. The last
argument passed the hash of the connected block as a pointer to 32
bytes. The hash was passed both as a pointer to a string and bytes
to allow `bpftrace` scripts to print the String. It was (incorrectly)
assumed that `bpftrace` cannot hex-format and print the block hash
given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p-=1;
  }
```

See also: bitcoin#22902 (comment)

This is a breaking change to the connect_block tracepoint API, however
there exist no release, including the tracepoint, yet.
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Oct 18, 2021
The tracepoint `validation:block_connected` was introduced in bitcoin#22006.
The first argument was the hash of the connected block as a pointer
to a C-like String. The last argument passed the hash of the
connected block as a pointer to 32 bytes. The hash was passed both as
a pointer to a string and bytes to allow `bpftrace` scripts to print
the String. It was (incorrectly) assumed that `bpftrace` cannot hex-
format and print the block hash given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p-=1;
  }
```

See also: bitcoin#22902 (comment)

This is a breaking change to the block_connected tracepoint API, however
this tracepoint has not yet been included in a release.
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Oct 18, 2021
The tracepoint `validation:block_connected` was introduced in bitcoin#22006.
The first argument was the hash of the connected block as a pointer
to a C-like String. The last argument passed the hash of the
connected block as a pointer to 32 bytes. The hash was only passed as
string to allow `bpftrace` scripts to print the hash. It was
(incorrectly) assumed that `bpftrace` cannot hex-format and print the
block hash given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p-=1;
  }
```

See also: bitcoin#22902 (comment)

This is a breaking change to the block_connected tracepoint API, however
this tracepoint has not yet been included in a release.
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Oct 18, 2021
The tracepoint `validation:block_connected` was introduced in bitcoin#22006.
The first argument was the hash of the connected block as a pointer
to a C-like String. The last argument passed the hash of the
connected block as a pointer to 32 bytes. The hash was only passed as
string to allow `bpftrace` scripts to print the hash. It was
(incorrectly) assumed that `bpftrace` cannot hex-format and print the
block hash given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p -= 1;
  }
```

See also: bitcoin#22902 (comment)

This is a breaking change to the block_connected tracepoint API, however
this tracepoint has not yet been included in a release.
fanquake added a commit that referenced this pull request Oct 19, 2021
…alidation:block_connected` tracepoint

53c9fa9 tracing: drop block_connected hash.toString() arg (0xb10c)

Pull request description:

  The tracepoint `validation:block_connected` was introduced in #22006.
  The first argument was the hash of the connected block as a pointer
  to a C-like String. The last argument passed the hash of the
  connected block as a pointer to 32 bytes. The hash was only passed as
  string to allow `bpftrace` scripts to print the hash. It was
  (incorrectly) assumed that `bpftrace` cannot hex-format and print the
  block hash given only the hash as bytes.

  The block hash can be printed in `bpftrace` by calling
  `printf("%02x")` for each byte of the hash in an `unroll () {...}`.
  By starting from the last byte of the hash, it can be printed in
  big-endian (the block-explorer format).

  ```C
    $p = $hash + 31;
    unroll(32) {
        $b = *(uint8*)$p;
        printf("%02x", $b);
        $p -= 1;
    }
  ```

  See also: #22902 (comment)

  This is a breaking change to the block_connected tracepoint API, however
  this tracepoint has not yet been included in a release.

ACKs for top commit:
  laanwj:
    Concept and code review ACK 53c9fa9
  jb55:
    ACK 53c9fa9

Tree-SHA512: f1b9e4e0ee45aae892e8bf38e04b5ee5fbc643d6e7e27d011b829ed8701dacf966a99b7c877c46cca8666b894a375633e62582c552c8203614c6f2b9c4087585
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Oct 19, 2021
… the `validation:block_connected` tracepoint

53c9fa9 tracing: drop block_connected hash.toString() arg (0xb10c)

Pull request description:

  The tracepoint `validation:block_connected` was introduced in bitcoin#22006.
  The first argument was the hash of the connected block as a pointer
  to a C-like String. The last argument passed the hash of the
  connected block as a pointer to 32 bytes. The hash was only passed as
  string to allow `bpftrace` scripts to print the hash. It was
  (incorrectly) assumed that `bpftrace` cannot hex-format and print the
  block hash given only the hash as bytes.

  The block hash can be printed in `bpftrace` by calling
  `printf("%02x")` for each byte of the hash in an `unroll () {...}`.
  By starting from the last byte of the hash, it can be printed in
  big-endian (the block-explorer format).

  ```C
    $p = $hash + 31;
    unroll(32) {
        $b = *(uint8*)$p;
        printf("%02x", $b);
        $p -= 1;
    }
  ```

  See also: bitcoin#22902 (comment)

  This is a breaking change to the block_connected tracepoint API, however
  this tracepoint has not yet been included in a release.

ACKs for top commit:
  laanwj:
    Concept and code review ACK 53c9fa9
  jb55:
    ACK 53c9fa9

Tree-SHA512: f1b9e4e0ee45aae892e8bf38e04b5ee5fbc643d6e7e27d011b829ed8701dacf966a99b7c877c46cca8666b894a375633e62582c552c8203614c6f2b9c4087585
@laanwj
Copy link
Member

laanwj commented Nov 10, 2021

Concept and light code review ACK, thanks for adding tracepoints!

Edit: see discussion please remove the ToString.

janus pushed a commit to BitgesellOfficial/bitgesell that referenced this pull request Nov 11, 2021
The tracepoint `validation:block_connected` was introduced in #22006.
The first argument was the hash of the connected block as a pointer
to a C-like String. The last argument passed the hash of the
connected block as a pointer to 32 bytes. The hash was only passed as
string to allow `bpftrace` scripts to print the hash. It was
(incorrectly) assumed that `bpftrace` cannot hex-format and print the
block hash given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

```C
  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p -= 1;
  }
```

See also: bitcoin/bitcoin#22902 (comment)

This is a breaking change to the block_connected tracepoint API, however
this tracepoint has not yet been included in a release.
Signed-off-by: Arnab Sen <arnabsen1729@gmail.com>
Signed-off-by: Arnab Sen <arnabsen1729@gmail.com>
@0xB10C
Copy link
Contributor

0xB10C commented Dec 6, 2021

Agree that a follow-up is better suited here.

@0xB10C
Copy link
Contributor

0xB10C commented Dec 6, 2021

I've just tested the log_utxos.bt on mainnet and it's giving me this output:

Spent  0b9ab1dc44cf8ff9a3b9d4Lost 20 events
94Lost 36 events
f6Lost 33 events
b241Lost 32 events
b2Lost 32 events
Spent  6ae7e6eb7cffLost 28 events
bcLost 43 events
faLost 46 events
09Lost 24 events
37Lost 19 events
2fLost 32 events
Spent  1bfaf48e84d8b3dc2c3ebe282d8842Lost 34 events
c0Lost 18 events
5e17Lost 17 events
8aLost 42 events
0dLost 39 events
7ee9Lost 31 events
Spent  bbc2c4ccbd1c3d6583cacd4a8572b2Lost 44 events

The tracepoints utxocache:add and utxocache:spent tracepoints are called very frequently during block connections causing events to be lost as the buffer fills before it read. Haven't tested if attaching to the two tracepoints via a BCC Python script or Rust program behaves differently.

I'm seeing events being lost during testnet and signet IBD too, however not as many as on mainnet (as the blocks contain fewer transactions and thus fewer changes to the UTXO set).

@0xB10C
Copy link
Contributor

0xB10C commented Dec 6, 2021

Let's handle it in a follow-up PR.

fwiw: @arnabsen1729 is working on a follow-up

@jb55
Copy link
Contributor

jb55 commented Dec 6, 2021 via email

@0xB10C
Copy link
Contributor

0xB10C commented Dec 6, 2021

Looking at the script, calling printf 32 times might be pretty slow relative to the incoming events. Is it possible to call printf once with 32 %02x entries in the format string?

Maybe, yes.

In BCC you can set the page count of the ring buffer. That worked for me in the past. You can control bpftrace's ring buffer page count with BPFTRACE_PERF_RB_PAGES (needs to be set to a power of two).

Running BPFTRACE_PERF_RB_PAGES=16384 bpftrace contrib/tracing/log_utxos.bt is the lowest page size that works for me here without dropping events. Default is 64.

@jb55
Copy link
Contributor

jb55 commented Dec 6, 2021

@0xB10C that seems to be a better solution, since I imagine people will have harder workloads than 32 printfs...

@0xB10C
Copy link
Contributor

0xB10C commented Dec 6, 2021

yes, I guess mentioning this on either the docs or examples page would be good. Could be done in @arnabsen1729 follow-up.

@jb55
Copy link
Contributor

jb55 commented Dec 6, 2021

if the page size is 4096 (some quick googling, not sure if correct), then 16384 pages is ~67 MB. seems pretty high but not unreasonable...

0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Dec 13, 2021
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Dec 13, 2021
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Dec 13, 2021
arnabsen1729 pushed a commit to arnabsen1729/bitcoin that referenced this pull request Dec 17, 2021
arnabsen1729 pushed a commit to arnabsen1729/bitcoin that referenced this pull request Dec 22, 2021
The documentation and examples for the fFlushForPrune argument of the
utxocache flush tracepoint weren't clear without looking at the code.

See these comments: bitcoin#22902 (comment)
RandyMcMillan pushed a commit to RandyMcMillan/mempool-tab that referenced this pull request Dec 23, 2021
4769342 [tracing] tracepoints to utxocache add, spent and uncache (Arnab Sen)
7d79993 [tracing] tracepoint for utxocache flushes (Arnab Sen)

Pull request description:

  This PR adds some of the UTXO set cache tracepoints proposed in bitcoin/bitcoin#20981 (comment). The first tracepoints were added in bitcoin#22006.

  tracepoint | description
  -- | --
  `utxocache:flush` | Is called after the caches and indexes are flushed
  `utxocache:add` | when a new coin is added to the UTXO cache
  `utxocache:spent` | when a coin is spent
  `utxocache:uncache` | when coin is removed from the UTXO cache

  The tracepoints are further documented in `docs/tracing.md` and the usage is shown via the two newly added example scripts in `contrib/tracing/`.

ACKs for top commit:
  laanwj:
    Code and documentation review ACK 4769342

Tree-SHA512: d6b4f435d3260de4c48b36956f9311f65ab3b52cd03b1e0a4ba9cf47a774d8c4b31878e222b11e0ba5d233a68f7567f8a367b12a6392f688c10c11529341e837
arnabsen1729 pushed a commit to arnabsen1729/bitcoin that referenced this pull request Dec 25, 2021
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin#22902 (comment)
arnabsen1729 pushed a commit to arnabsen1729/bitcoin that referenced this pull request Dec 30, 2021
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin#22902 (comment)
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Feb 15, 2022
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin#22902 (comment)
arnabsen1729 pushed a commit to arnabsen1729/bitcoin that referenced this pull request Feb 18, 2022
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin#22902 (comment)

- doc: note that there can be temporary UTXO caches
    Bitcoin Core uses temporary clones of it's _main_ UTXO cache in some
    places. The utxocache:add and :spent tracepoints are triggered when
    temporary caches are changed too. This is documented.
0xB10C added a commit to 0xB10C/bitcoin that referenced this pull request Feb 20, 2022
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin#22902 (comment)

- doc: note that there can be temporary UTXO caches
    Bitcoin Core uses temporary clones of it's _main_ UTXO cache in some
    places. The utxocache:add and :spent tracepoints are triggered when
    temporary caches are changed too. This is documented.
fanquake added a commit to bitcoin-core/gui that referenced this pull request Feb 20, 2022
… for #22902

799968e tracing: misc follow-ups to 22902 (0xb10c)
36a6584 tracing: correctly scope utxocache:flush tracepoint (Arnab Sen)

Pull request description:

  This PR is a follow-up to the [#22902](bitcoin/bitcoin#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 799968e

Tree-SHA512: ebb096cbf991c551c81e4339821f10d9768c14cf3d8cb14d0ad851acff5980962228a1c746914c6aba3bdb27e8be53b33349c41efe8bab5542f639916e437b5f
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Feb 20, 2022
…coin#22902

799968e tracing: misc follow-ups to 22902 (0xb10c)
36a6584 tracing: correctly scope utxocache:flush tracepoint (Arnab Sen)

Pull request description:

  This PR is a follow-up to the [bitcoin#22902](bitcoin#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 799968e

Tree-SHA512: ebb096cbf991c551c81e4339821f10d9768c14cf3d8cb14d0ad851acff5980962228a1c746914c6aba3bdb27e8be53b33349c41efe8bab5542f639916e437b5f
laanwj added a commit to bitcoin-core/gui that referenced this pull request Apr 6, 2022
76c60d7 test: validation:block_connected tracepoint test (0xb10c)
260e28e test: utxocache:* tracepoint tests (0xb10c)
34b27ba test: net:in/out_message tracepoint tests (0xb10c)
c934087 test: checks for tracepoint tests (0xb10c)

Pull request description:

  This adds functional tests for the USDT tracepoints added in bitcoin/bitcoin#22006 and bitcoin/bitcoin#22902. This partially fixes #23296. The tests **are probably skipped** on most systems as these tests require:
  - a Linux system with a kernel that supports BPF (and available kernel headers)
  - that Bitcoin Core is compiled with tracepoints for USDT support (default when compiled with depends)
  - [bcc](https://github.com/iovisor/bcc) installed
  - the tests are run with a privileged user that is able to e.g. do BPF syscalls and load BPF maps

  The tests are not yet run in our CI as the CirrusCI containers lack the required permissions (see bitcoin/bitcoin#23296 (comment)). Running the tests in a VM in the CI could work, but I haven't experimented with this yet. The priority was to get the actual tests done first to ensure the tracepoints work as intended for the v23.0 release. Running the tracepoint tests in the CI is planned as the next step to finish #23296.

  The tests can, however, be run against e.g. release candidates by hand. Additionally, they provide a starting point for tests for future tracepoints. PRs adding new tracepoint should include tests. This makes reviewing these PRs easier.

  The tests require privileges to execute BPF sycalls (`CAP_SYS_ADMIN` before Linux kernel 5.8 and `CAP_BPF` and `CAP_PERFMON` on 5.8+) and permissions to `/sys/kernel/debug/tracing/`. It's currently recommended to run the tests in a virtual machine (or on a VPS) where it's sensible to use the `root` user to gain these privileges. Never run python scripts you haven't carefully reviewed with `root` permissions! It's unclear if a non-root user can even gain the required privileges. This needs more experimenting.

  The goal here is to test the tracepoint interface to make sure the [documented interface](https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#tracepoint-documentation) does not break by accident. The tracepoints expose implementation details. This means we also need to rely on implementation details of Bitcoin Core in these functional tests to trigger the tracepoints. An example is the test of the `utxocache:flush` tracepoint: On Bitcoin Core shutdown, the UTXO cache is flushed twice. The corresponding tracepoint test expects two flushes, too - if not, the test fails. Changing implementation details could cause these tests to fail and the tracepoint API to break. However, we purposefully treat the tracepoints only as [**semi-stable**](https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#semi-stable-api). The tracepoints should not block refactors or changes to other internals.

ACKs for top commit:
  jb55:
    tACK 76c60d7
  laanwj:
    Tested ACK 76c60d7

Tree-SHA512: 9a63d945c68102e59d751bd8d2805ddd7b37185408fa831d28a9cb6641b701961389b55f216c475df7d4771154e735625067ee957fc74f454ad7a7921255364c
janus pushed a commit to BitgesellOfficial/bitgesell that referenced this pull request Jul 24, 2022
- mention 'Lost X events' workaround
- clarify flush tracepoint docs
- fix typo in tracepoint context
- clarify flush for prune
    The documentation and examples for the `fFlushForPrune` argument
    of the utxocache flush tracepoint weren't clear without looking
    at the code.

    See these comments: bitcoin/bitcoin#22902 (comment)

- doc: note that there can be temporary UTXO caches
    Bitcoin Core uses temporary clones of it's _main_ UTXO cache in some
    places. The utxocache:add and :spent tracepoints are triggered when
    temporary caches are changed too. This is documented.
Fabcien added a commit to Bitcoin-ABC/bitcoin-abc that referenced this pull request Nov 30, 2022
Summary:
```
The tracepoint `validation:block_connected` was introduced in #22006.
The first argument was the hash of the connected block as a pointer
to a C-like String. The last argument passed the hash of the
connected block as a pointer to 32 bytes. The hash was only passed as
string to allow `bpftrace` scripts to print the hash. It was
(incorrectly) assumed that `bpftrace` cannot hex-format and print the
block hash given only the hash as bytes.

The block hash can be printed in `bpftrace` by calling
`printf("%02x")` for each byte of the hash in an `unroll () {...}`.
By starting from the last byte of the hash, it can be printed in
big-endian (the block-explorer format).

  $p = $hash + 31;
  unroll(32) {
      $b = *(uint8*)$p;
      printf("%02x", $b);
      $p -= 1;
  }

See also: bitcoin/bitcoin#22902 (comment)

This is a breaking change to the block_connected tracepoint API, however
this tracepoint has not yet been included in a release.
```

Backport of [[bitcoin/bitcoin#23302 | core#23302]].

Also updated sigops => sigchecks in the bt script, and updated the detection so it's more obvious that it's enabled.

Test Plan:
Build and run with tracing enabled, then:
  sudo bpftrace ../contrib/tracing/connectblock_benchmark.bt 0 0 25

Reviewers: #bitcoin_abc, sdulfari

Reviewed By: #bitcoin_abc, sdulfari

Subscribers: sdulfari

Differential Revision: https://reviews.bitcoinabc.org/D12674
Fabcien pushed a commit to Bitcoin-ABC/bitcoin-abc that referenced this pull request Dec 1, 2022
Summary:
```
The tracepoints are further documented in docs/tracing.md and the usage is shown via the two newly added example scripts in contrib/tracing/.
```

Backport of [[bitcoin/bitcoin#22902 | core#22902]].
Backport of [[bitcoin/bitcoin#23907 | core#23907]].

Notes:
 - The amount is passed as string because our type can't be converted to int
 - CTxOut and CCoin accessors are used where applicable
 - I removed the casts that are both useless and even mixing stding and posix types

Test Plan:
Build with tracing, run bitcoind, then:
  sudo ../contrib/tracing/log_utxocache_flush.py ./src/bitcoind
  sudo bpftrace ../contrib/tracing/log_utxos.bt

Reviewers: #bitcoin_abc, PiRK

Reviewed By: #bitcoin_abc, PiRK

Subscribers: PiRK

Differential Revision: https://reviews.bitcoinabc.org/D12715
@bitcoin bitcoin locked and limited conversation to collaborators Dec 6, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

9 participants