Additional information that may be relevant for reviewers:

• I've documented my progress on including sys/sdt.h in tracing: include tracepoints in GUIX builds #23297
• Build support for the USDT was initially added in eBPF Linux tracepoints #19866. Some initial discussion on tracepoints in release builds took place in this thread eBPF Linux tracepoints #19866 (comment). Some more discussion in a bitcoin-core-dev meeting January 2021.
• There was a PR review club on tracing: first tracepoints and documentation on User-Space, Statically Defined Tracing (USDT) #22006
• We have documentation listing tracepoints in a binary in doc/tracing.md.
• The tracepoints are currently not automatically/CI tested (tracing: tests for USDT tracepoints  #23296). Merging this now could leave us with broken tracepoints in a release build.

I've tested the GUIX binaries on aarch64-linux-gnu, arm-linux-gnueabihf, x86_64-linux-gnu and on x86_64-w64-mingw32. I don't have hardware to test on x86_64-apple-darwin19, powerpc64le-linux-gnu, powerpc64-linux-gnu, or powerpc64-linux-gnu (though I might try running the binaries in qemu). Any help testing on these platforms would be appreciated. Of course, testing and review on the already tested platforms is welcome too!

¹ bpftrace isn't available on Ubuntu 21.10 for armhf. BCC is available, but compiling the C code didn't work. Presumably it only worrks on 64-bit? Needs further testing.
² Maybe the x86_64-apple-darwin19 binaries contain tracepoints that can be listed with e.g. dtrace on macOS? No, tracepoints aren't compiled in as this check fails. This is OK, we currently only support tracepoints on Linux.

@DrahtBot !request_GUIX_build

There has been light conceptual agreement on including the Userspace, Statically Defined Tracing tracepoints in Bitcoin Core release builds. This, for example, enables user to hook into production deployments, if they need to

Big concept ACK

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

• #22708 (build, qt: Add Wayland support for Linux builds with depends by hebasto)
• #22555 (build: Fix make apk for Android w/ non-default SOURCES_PATH in depends by hebasto)
• #22552 (build: Improve depends build system robustness by hebasto)

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.

Any help testing on these platforms would be appreciated.

As I have a running RV64 system (SiFive Unmatched) I can give it a try on riscv64-linux-gnu. Which steps did you follow for "synced signet" and "tracepoints tested"? Literally just sync signet, and try the tracepoint examples?

Concept ACK, will test soon

I can give it a try on riscv64-linux-gnu.

Thanks @laanwj! That would be awesome!

Which steps did you follow for "synced signet" and "tracepoints tested"? Literally just sync signet, and try the tracepoint examples?

Yes. By syncing signet I just wanted to make sure nothing is horribly broken on that arch (I see no reason why it should be). Running the tests suits should work as well. I ran the p2p_monitor.py and a bpftrace example to test the tracepoints. Happy to do further testing if needed!

We'll be discussing this PR in the BItcoin Core PR review club this Wednesday at 17:00 UTC: https://bitcoincore.reviews/23724

Tested on riscv64-linux-gnu:

• ✔️ Tracepoints are present in the binary (checked only bitcoind and bitcoin-qt)

$ gdb bitcoind
GNU gdb (Debian 10.1-2) 10.1.90.20210103-git
(gdb) info probes
Type Provider   Name             Where              Semaphore Object
stap net        inbound_message  0x00000000000ea198           /…/bitcoin-070570806404/bin/bitcoind
…

• ✔️ Signet sync from scratch to successful to height=68616
• 🤷‍♀️ Tracepoints tested

No bcc or bpftrace packages exist for RISC-V debian, so I had to build them from source (against clang13).

Bcc builds successfully (including python module), unfortunately, bpftrace doesn't support riscv64 at the moment:

CMake Error at src/arch/CMakeLists.txt:14 (message):
  Unsupported architecture: riscv64

Trying to run the python scripts runs into parse errors:

# ./log_raw_p2p_msgs.py …/bitcoin-070570806404/bin/bitcoind
Parse error:
    -8@s2 8@s3 8@a0 8@24(s1) 8@a5 8@a4
---------^
Parse error:
    -8@s2 8@s3 8@a0 8@24(s1) 8@a5 8@a4
--------------^
Parse error:
    -8@s2 8@s3 8@a0 8@24(s1) 8@a5 8@a4
-------------------^
Parse error:
    -8@s2 8@s3 8@a0 8@24(s1) 8@a5 8@a4

So I think this is a no-go for now.

Thanks @laanwj!! I've updated the table in #23724 (comment).

From the parse error it seems like bcc isn't able to parse the register names in the systemtap ELF notes in bitcoind. There was some RISC-V work in iovisor/bcc#3678 which might have touched this. Not sure though. I'm getting a similar error on arm-linux-gnueabihf:

$ python3 log_raw_p2p_msgs.py ../../../bitcoin-0729f577f0e2/bin/bitcoind
Parse error:
    -8@r8 4@r6 4@r0 4@[r5, #12] 4@r3 4@r2
---------^
Parse error:
    -8@r8 4@r6 4@r0 4@[r5, #12] 4@r3 4@r2
--------------^
Parse error:
    -8@r8 4@r6 4@r0 4@[r5, #12] 4@r3 4@r2
-------------------^
Parse error:
    -8@r8 4@r6 4@r0 4@[r5, #12] 4@r3 4@r2
--------------------------^
[..]

I haven't tested the tracepoints with the Systemtap tools at all. Maybe this can be used on arm-linux-gnueabihf, and riscv64-linux-gnu? If not, we might not want to build binaries with tracepoints for these platforms. Only supporting x86_64-linux-gnu and aarch64-linux-gnu in release builds for now.

I've also checked that this check fails for x86_64-apple-darwin19 and x86_64-w64-mingw32. Also USDT tracing = no is being printed during configure. This means we don't need to copy the new systemtap depends package for these two platforms. No tracepoints on macOS and Windows.

I've update the table in #23724 (comment).

From the parse error it seems like bcc isn't able to parse the register names in the systemtap ELF notes in bitcoind. There was some RISC-V work in iovisor/bcc#3678

Thanks, I'll look into that patch. Edit: I am running the version from git, so should have that merged PR already, so unfortunately it doesn't fix it.

If not, we might not want to build binaries with tracepoints for these platforms. Only supporting x86_64-linux-gnu and aarch64-linux-gnu in release builds for now.

It depends, if compiler support is working, and it's purely an issue with the tooling (bcc, bpftrace) I'd argue there is no reason for disabling it on those platforms. It will work as soon as the tools are updated to support the architectures (especially for RISC-V I expect this to be happening soon). I guess the problem is that we can't really test that the tracepoints are inserted correctly in the binary?

Or maybe we can through gdb? E.g. put a breakpoint at a tracepoint and then inspect the arguments manually.

Edit: I checked bcc (as of commit 52900a435de85e706f5280f4a184374dd729c58e, current HEAD) and FWIW, specialized argumentparsers only exist for the following platforms:

class ArgumentParser_aarch64 : public ArgumentParser {
class ArgumentParser_powerpc64 : public ArgumentParser {
class ArgumentParser_s390x : public ArgumentParser {
class ArgumentParser_x64 : public ArgumentParser {

There is no general behavior: the base class is a pure virtual base class. So while I haven't checked which one it's instantiating for riscv64-linux-gnu and arm-linux-gnueabihf, it can't actually be correct 😄

Edit.2: On unsupported architectures, you get the _x64 one for free !!!

#ifdef __aarch64__
  ArgumentParser_aarch64 parser(arg_fmt);
#elif __powerpc64__
  ArgumentParser_powerpc64 parser(arg_fmt);
#elif __s390x__
  ArgumentParser_s390x parser(arg_fmt);
#else
  ArgumentParser_x64 parser(arg_fmt);
#endif

Concept ACK, running the guix build

Testing on Ubuntu 18, was getting segfaults for log_utxos.bt and connectblock_benchmark.bt. Had to build bpftrace from source with the following versions:

• bpftrace v0.12.1
• bcc v0.8.0 (required to build bpftrace from source)

Thanks for your comments @fanquake. I've addressed them in my last push.

Concept ACK on adding tracepoints to the release builds, assuming there is 0 overhead for users who don't care about them.

This isn't the case. There is bit of overhead, even if it's only slightly more than zero overhead. When we compile a binary without tracepoints, the arguments (e.g. function calls) passed to the TRACEx macros are optimized out. When tracepoints are enabled, these arguments and executed functions cause additional instructions to be executed.The tracepoint it self is a single NOP instruction. No additional instructions are executed for the actual tracepoint when not used (the arguments are still processed).

In terms of overhead:

binary without tracepoints < binary with tracepoints < binary with tracepoints and tracepoints being used

As an example, I'm looking at the net:inbound_message tracepoint in net_processing.cpp at commit 767c012. This is the relevant code section:

To count the number of executed instructions I'm using gdb and set two breakpoints. The first breakpoint in line 4141 and the second breakpoint in line 4152. When hitting the first breakpoint, I run record btrace (see GDB Process Record and Replay) and continue to the second breakpoint. There I print information about the recording with info record and record end. This prints the number of executed instructions between the two breakpoints. I do this for a binary with and a binary without breakpoints.

To automate this process you can use the following gdb script:

b net_processing.cpp:4141
commands 1
  record btrace
  continue
end

b net_processing.cpp:4152
commands 2
  info record
  record stop
  continue
end

run

$ gdb --batch --command=net_inboundmsg_ins.gdb --args bitcoind -debug=net | grep -e 'received\:\|instructions in'

This interlaces bitcoind's net logging for received messages with the number of instructions being executed. Here is the output it produced for me on x86_64-linux-gnu (Intel CPU):

Recorded 469 instructions in 28 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: version (102 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: verack (0 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: sendheaders (0 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: sendcmpct (9 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: sendcmpct (9 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: ping (8 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: getheaders (1029 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: feefilter (8 bytes) peer=0
2021-12-17T17:24:53Z received: feefilter of 0.00001000 BTC/kvB from peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:53Z received: pong (8 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:54Z received: headers (22683 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:54Z received: block (1512354 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:55Z received: block (1439515 bytes) peer=0
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:55Z received: block (1511944 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:56Z received: block (1015177 bytes) peer=0
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:56Z received: block (743309 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:58Z received: block (1448974 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:24:59Z received: block (324652 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:00Z received: block (1478186 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:04Z received: block (1547585 bytes) peer=0
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:13Z received: version (104 bytes) peer=3
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:13Z received: block (57225 bytes) peer=0
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:13Z received: version (102 bytes) peer=4
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:13Z received: verack (0 bytes) peer=3
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:13Z received: block (1692970 bytes) peer=0
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:18Z received: sendheaders (0 bytes) peer=3
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:18Z received: verack (0 bytes) peer=4
Recorded 275 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:18Z received: sendcmpct (9 bytes) peer=3
Recorded 278 instructions in 26 functions (0 gaps) for thread 21 (Thread 0x7fff38868640 (LWP 60195)).
2021-12-17T17:25:18Z received: block (909231 bytes) peer=0

Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:49:51Z received: version (102 bytes) peer=0
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: version (102 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: verack (0 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: sendheaders (0 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: sendcmpct (9 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: sendcmpct (9 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: ping (8 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: getheaders (1029 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: feefilter (8 bytes) peer=2
2021-12-17T17:50:18Z received: feefilter of 0.00001000 BTC/kvB from peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: pong (8 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:18Z received: headers (23007 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:19Z received: block (1512354 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:19Z received: block (1439515 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:20Z received: block (1511944 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:20Z received: block (1015177 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:21Z received: block (743309 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:21Z received: block (1448974 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:21Z received: block (324652 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:22Z received: block (1478186 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:22Z received: block (1547585 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:25Z received: block (57225 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:25Z received: block (1692970 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:28Z received: block (909231 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:29Z received: version (120 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:29Z received: block (1487873 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:31Z received: block (1597437 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:32Z received: wtxidrelay (0 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:32Z received: block (1482700 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:33Z received: sendaddrv2 (0 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:33Z received: verack (0 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:33Z received: block (1537427 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:33Z received: block (1560096 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:34Z received: sendheaders (0 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:34Z received: block (755937 bytes) peer=2
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:34Z received: sendcmpct (9 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:34Z received: sendcmpct (9 bytes) peer=3
Recorded 4 instructions in 1 functions (0 gaps) for thread 21 (Thread 0x7fff2a7fc640 (LWP 85161)).
2021-12-17T17:50:34Z received: block (822822 bytes) peer=2

When using the binary with tracepoints, ~274 more instructions are executed between the two breakpoints compared to the binary without breakpoints. That's why, when adding tracepoints, we don't do expensive computations only needed for the tracepoints and only use data that's already present. I do think 274 additional instructions (for this tracepoint) isn't a substantial price to pay and is close to zero overhead. I haven't done these measurements for the other tracepoints though (probably makes sense to to them).

@0xB10C why does the one with tracepoints say instructions in 26 functions and the one without tracepoints says: instructions in 1 functions? is this counting the same things?

@jb55 If ENABLE_TRACING is defined, the TRACE6(context, event, a, b, c, d, e, f) macro is replaced by the DTRACE_PROBE6(context, event, a, b, c, d, e, f) macro. If the arguments a, b, c, d, e, f are the return values of functions (that's the case for all net:inbound_message arguments), these get compiled in, executed, and counted by gdb. You can probably step into the functions and count them manually too with gdb.

If ENABLE_TRACING is not defined, TRACE6(context, event, a, b, c, d, e, f) macro is an empty macro. There is no code being generated. None of the argument functions are compiled in and executed.

On that note and if we think e.g. ~274 instructions are still too much: We might be able branch before we execute the tracepoint arguments based on e.g. a -tracing command line argument. You'd need to specifically enable tracing for the tracepoints to be reached. However, at the moment I prefer it as is.

if (gArgs.GetBoolArg("-tracing", false)) {
    TRACE6(..)
}

(or put this check in the macros too)

I guess I'm surprised that those calls that simply return pointers aren't inlined, but I'm guessing that's because of some vtable indirection or something. It looks like ConnectionTypeAsString does some work, doesn't this violate our recommendation of doing no work in tracepoints? It's out of scope for this PR of course, but it would be interesting to see the instruction diff by just returning the enum instead of the enum string (I'll go ahead and try this to test out your gdb script).

@0xB10C

before:

Recorded 293 instructions in 27 functions

after with this patch:

diff --git a/src/net.h b/src/net.h
index 9623a630e7..6f99d56661 100644
--- a/src/net.h
+++ b/src/net.h
@@ -660,6 +660,8 @@ public:
 
     std::string ConnectionTypeAsString() const { return ::ConnectionTypeAsString(m_conn_type); }
 
+    ConnectionType GetConnectionType() const { return m_conn_type; }
+
     /** A ping-pong round trip has completed successfully. Update latest and minimum ping times. */
     void PongReceived(std::chrono::microseconds ping_time) {
         m_last_ping_time = ping_time;
diff --git a/src/net_processing.cpp b/src/net_processing.cpp
index d67ced99ea..6f8209d21c 100644
--- a/src/net_processing.cpp
+++ b/src/net_processing.cpp
@@ -4146,7 +4146,7 @@ bool PeerManagerImpl::ProcessMessages(CNode* pfrom, std::atomic<bool>& interrupt
     TRACE6(net, inbound_message,
         pfrom->GetId(),
         pfrom->m_addr_name.c_str(),
-        pfrom->ConnectionTypeAsString().c_str(),
+        pfrom->GetConnectionType(),
         msg.m_command.c_str(),
         msg.m_recv.size(),
         msg.m_recv.data()

the number of instructions becomes trivial:

Recorded 9 instructions in 1 functions

I wasn't able to do this same test on my AMD because gdb doesn't support branch tracing on AMDs apparently :(

@jb55 Oh wouldn't have thought that ConnectionTypeAsString() was responsible for the majority of these instructions. Thanks for looking into this! I get the same results on Intel:

Recorded 9 instructions in 1 functions

However, I think as soon as the ConnectionType enum is changed, the tracing scripts might break/will confuse the connection types and the tracepoint documentation will be outdated. Additionally, we might want to cast here as we implicitly convert a scoped enum to an int (?). Diving deeper into this here is probably a bit off-topic, but I think it shows that we might want to iterate before having the tracepoints enabled in a release.

GUIX build hashes for c1df11e:

$ find guix-build-$(git rev-parse --short=12 HEAD)/output/ -type f -print0 | env LC_ALL=C sort -z | xargs -r0 sha256sum
b613183271f4b940348c02d98da60123a0d7ae42a79ab06f83c5d23617f8951b  guix-build-c1df11eafc8c/output/aarch64-linux-gnu/SHA256SUMS.part
275d2c82c7680220331f08451143deb4856c17fd03c549b15eb3446cfd4e6342  guix-build-c1df11eafc8c/output/aarch64-linux-gnu/bitcoin-c1df11eafc8c-aarch64-linux-gnu-debug.tar.gz
479767ad6e6dca437a58f93a0148d9c3d97374a5d70978801bd898b8c03f7cf4  guix-build-c1df11eafc8c/output/aarch64-linux-gnu/bitcoin-c1df11eafc8c-aarch64-linux-gnu.tar.gz
82c5dfdfe2551590b57b004f4944dba39d359baa13ced6344ef1e2ce940d36ed  guix-build-c1df11eafc8c/output/arm-linux-gnueabihf/SHA256SUMS.part
89471c634ba5ef3c5e0465c2f2f3386cf66c3ff1b2eafaf6dff0faf9e4781af7  guix-build-c1df11eafc8c/output/arm-linux-gnueabihf/bitcoin-c1df11eafc8c-arm-linux-gnueabihf-debug.tar.gz
9c94535ff1cb7dc3c8359dd13312f2b9353ed94a4b2569bea9f4e0f0869e0418  guix-build-c1df11eafc8c/output/arm-linux-gnueabihf/bitcoin-c1df11eafc8c-arm-linux-gnueabihf.tar.gz
6182d4b3a6cf03029b1d85df6a5f16db5929dd8b165066be807d328da995719c  guix-build-c1df11eafc8c/output/dist-archive/bitcoin-c1df11eafc8c.tar.gz
f6893a6aa46afe1846c97862367e8c3426a13f5a09f342cfc6f0a74d95eb25e7  guix-build-c1df11eafc8c/output/powerpc64-linux-gnu/SHA256SUMS.part
ca591256fe08a17991230ba82ba9ef9ddccb4d73ad7f781d3c2e1665818d7387  guix-build-c1df11eafc8c/output/powerpc64-linux-gnu/bitcoin-c1df11eafc8c-powerpc64-linux-gnu-debug.tar.gz
7930a0806c053741b2bc14f2f738f7d2a5c04a46f4a1dd8b0b01614cd28c26f5  guix-build-c1df11eafc8c/output/powerpc64-linux-gnu/bitcoin-c1df11eafc8c-powerpc64-linux-gnu.tar.gz
2e6865291ca5b4f6e1b4dddb2c5f6f266a77a22990abf0dc01c128625924443e  guix-build-c1df11eafc8c/output/powerpc64le-linux-gnu/SHA256SUMS.part
909310911698d40e85078f5d54030e1f7273f2d88b8a472f9bbbfe0d74ee5487  guix-build-c1df11eafc8c/output/powerpc64le-linux-gnu/bitcoin-c1df11eafc8c-powerpc64le-linux-gnu-debug.tar.gz
bd78a8468c899078b55fa9626791f7ea60e319f0fa7c31ddd8b3118e60d76945  guix-build-c1df11eafc8c/output/powerpc64le-linux-gnu/bitcoin-c1df11eafc8c-powerpc64le-linux-gnu.tar.gz
44bad54bf4aab886c919c96bfef6e82f0d5e0ad094ab571c81c617e6d434fad7  guix-build-c1df11eafc8c/output/riscv64-linux-gnu/SHA256SUMS.part
d69d02cf9fbb1124ec858dcc0e8f3f345031fde6a677eb720a6d6d92580cc11e  guix-build-c1df11eafc8c/output/riscv64-linux-gnu/bitcoin-c1df11eafc8c-riscv64-linux-gnu-debug.tar.gz
86a8ad2bc5bda6ff9e6a502e2e05f32e410778dbcb61c3e96ff0cf2e784c1720  guix-build-c1df11eafc8c/output/riscv64-linux-gnu/bitcoin-c1df11eafc8c-riscv64-linux-gnu.tar.gz
b0c70a0fb9f165a74d47672775007a74298c27f3ee1834b9cb2f3767fc75e8ed  guix-build-c1df11eafc8c/output/x86_64-apple-darwin/SHA256SUMS.part
66cca84f5cb254654f4cd482c9c3364c97f754475cf4850a1d6226d0c419d65f  guix-build-c1df11eafc8c/output/x86_64-apple-darwin/bitcoin-c1df11eafc8c-osx-unsigned.dmg
d7dee56cea21d26ef8da8ae74d5741448713131827fa4e988c58a4694a1ca14d  guix-build-c1df11eafc8c/output/x86_64-apple-darwin/bitcoin-c1df11eafc8c-osx-unsigned.tar.gz
37ff6d2dca19df4697f4dd352953ee1392b4b857cd92b54ba81b93019deedb7c  guix-build-c1df11eafc8c/output/x86_64-apple-darwin/bitcoin-c1df11eafc8c-osx64.tar.gz
7adcff8cd68fcca18f91c5ddc2a274558cbf844b9538ade395167a70625ce04a  guix-build-c1df11eafc8c/output/x86_64-linux-gnu/SHA256SUMS.part
fd28efd1e6bd7e71ff0dd13480ce6e992be062f95a975157204ab206886ebf9e  guix-build-c1df11eafc8c/output/x86_64-linux-gnu/bitcoin-c1df11eafc8c-x86_64-linux-gnu-debug.tar.gz
349a67997624bec4b5909378a32a32f522d2343af3131d2214150f0436203501  guix-build-c1df11eafc8c/output/x86_64-linux-gnu/bitcoin-c1df11eafc8c-x86_64-linux-gnu.tar.gz
e5b3f76e29b3d3f378ec152fe7c4253e38b79eee3347c16f6dcab250e43355fe  guix-build-c1df11eafc8c/output/x86_64-w64-mingw32/SHA256SUMS.part
b24d134d0c59010df891032713479fb3d66efb2753537a60e8d44e5aae816de6  guix-build-c1df11eafc8c/output/x86_64-w64-mingw32/bitcoin-c1df11eafc8c-win-unsigned.tar.gz
6d003e820bc05f7e366fcc839670d9872e4087ce1d8acda23990c1b9f025274d  guix-build-c1df11eafc8c/output/x86_64-w64-mingw32/bitcoin-c1df11eafc8c-win64-debug.zip
37a35e793c7fb8800f2f48afac3d9a314c63938e071a704fcde5f4d7f54f8512  guix-build-c1df11eafc8c/output/x86_64-w64-mingw32/bitcoin-c1df11eafc8c-win64-setup-unsigned.exe
7273cde4f8155f247715da7d6e06b90eda69605b4436e5d35a09ded6b3c18fde  guix-build-c1df11eafc8c/output/x86_64-w64-mingw32/bitcoin-c1df11eafc8c-win64.zip

At first I wondered why these changed from #23724 (review), but I remembered that I did rebase before pushing. My hashes for 0705708 matched with fanquake's.

@0xB10C

However, I think as soon as the ConnectionType enum is changed, the tracing scripts might break/will confuse the connection types and the tracepoint documentation will be outdated. Additionally, we might want to cast here as we implicitly convert a scoped enum to an int (?).

All these issues should be solved by #23809

-        pfrom->ConnectionTypeAsString().c_str(),
+        pfrom->GetConnectionType(),

This keeps coming back: please don't pass strings that are generated on the fly to tracepoints. We should add a rule about this.

I've checked the utxocache:add and the utxocache:spent tracepoints. Both only add an extra 4 executed instructions. I'm assuming utxocache:uncache behaves similarly as the same arguments are passed.

The validation:block_connected tracepoint also seems to be more on the expensive side with "Recorded 8229 instructions in 80 functions". This includes, e.g. calculating the hash of the block and GetTimeMicros(). I'd argue that this is however still inexpensive compared to the total cost of validating a block.

For the utxocache:flush tracepoint, gdb reports "Recorded 171 instructions in 19 functions". These are mainly from GetTimeMicros(). If needed, dropping GetTimeMicros() could be a possibility here. Could be done in the follow-up to #22902.

To be fair in this case it's not really generated, the switch returns
static strings

I'm fairly sure the way c++ strings work, even though it returns static strings, it still does an allocation and copy (from the C string in .rodata) every time (then deallocating it again afterwards).

It's possible I'm wrong and modern compilers are smart enough to avoid it (can it see through std::string("static c-string").c_str() ?, but wouldn't bet on it.

I'll look into prematurely optimizing the other tracepoints as well,
especially the one that is taking 8000 instructions (wtf?)

In any case I'm happy that we have a way to measure and quantify the number of instructions generated by a tracepoint now!

This change is looking good now. I don't think it necessarily has to wait for #23809 or #23819 to be merged first, but we'd want those (and any other changes that reduce tracepoint overheads) merged for 23.0. If you'd like to have reviewers perform a Guix build of this PR, I'd suggest rebasing on master, so we don't have to worry about mismatches from a recent determinism issue in Qt.

Thanks, rebased.

Agree that we want to have these before 23.0:

• tracing: reduce instructions generated by net:message tracepoints #23809
• ConnectBlock: don't serialize block hash twice #23819
• tracing: utxocache tracepoints follow up for #22902 #23907
• and some automatic tracepoint testing (tracing: tests for USDT tracepoints  #23296) and/or RC build testing

Thanks, rebased.

Could you also integrate this change, fanquake@02dbe04, into your second commit.

Could you also integrate this change, fanquake@02dbe04, into your second commit.

Done, thanks!

Running a GUIX build now.

GUIX builds for 6200fbf:

$ find guix-build-$(git rev-parse --short=12 HEAD)/output/ -type f -print0 | env LC_ALL=C sort -z | xargs -r0 sha256sum
92da8c535d4b1f07c04fb235a6c5806ae46f5abeed9c123785a6be96911dc831  guix-build-6200fbf54fa9/output/aarch64-linux-gnu/SHA256SUMS.part
0dd21a5a9c8d0d8cb3f537359a722d0431d235e37cc4a2d38c1e87f025406f29  guix-build-6200fbf54fa9/output/aarch64-linux-gnu/bitcoin-6200fbf54fa9-aarch64-linux-gnu-debug.tar.gz
8085b6034858d6d59f8223dc06b659549cf05021f057580b24958acba5d3fae7  guix-build-6200fbf54fa9/output/aarch64-linux-gnu/bitcoin-6200fbf54fa9-aarch64-linux-gnu.tar.gz
e8537078c389e1374d49f43e8e52512030089e397d1a667e78df3530de1bf2d9  guix-build-6200fbf54fa9/output/arm-linux-gnueabihf/SHA256SUMS.part
148c1574b8edbd6baeaa77c807f6d3a17159b49193c777978fe99279b42732bd  guix-build-6200fbf54fa9/output/arm-linux-gnueabihf/bitcoin-6200fbf54fa9-arm-linux-gnueabihf-debug.tar.gz
4a6b2162c08d986ae4df147f9e50f90c039e7ca62b283da9d7fc4308e0757f00  guix-build-6200fbf54fa9/output/arm-linux-gnueabihf/bitcoin-6200fbf54fa9-arm-linux-gnueabihf.tar.gz
1b150b40541260de2f4f905a68db7b86339d792f404ee4c275a57d5b45f3ce1a  guix-build-6200fbf54fa9/output/dist-archive/bitcoin-6200fbf54fa9.tar.gz
1f6f3ec14f6ad98391746cd73c7aabc722ddf66d720c46fbdc9c2aebbb1d0232  guix-build-6200fbf54fa9/output/powerpc64-linux-gnu/SHA256SUMS.part
869cd22a0f1eb6721f8549ca690cec1a1d54bb8305e1f363ce0b6d2a6d654277  guix-build-6200fbf54fa9/output/powerpc64-linux-gnu/bitcoin-6200fbf54fa9-powerpc64-linux-gnu-debug.tar.gz
08288ab32d123dc7872dd9fcc2af24695004da171109eec9ccc9600d8efba8b3  guix-build-6200fbf54fa9/output/powerpc64-linux-gnu/bitcoin-6200fbf54fa9-powerpc64-linux-gnu.tar.gz
5e783d7c7b0ca80e682be432c81ae1758561ec9273f20b521653417ae73e2e9a  guix-build-6200fbf54fa9/output/powerpc64le-linux-gnu/SHA256SUMS.part
72daa19fe9a2724f8cb30faedb99feac633c1456d551d81c820a6226b54fb4a8  guix-build-6200fbf54fa9/output/powerpc64le-linux-gnu/bitcoin-6200fbf54fa9-powerpc64le-linux-gnu-debug.tar.gz
721344bd6a6e0a0cbb90c769e949f59449e6a90bc75bc4ade487664d29459685  guix-build-6200fbf54fa9/output/powerpc64le-linux-gnu/bitcoin-6200fbf54fa9-powerpc64le-linux-gnu.tar.gz
2996e463e4296c783a0cf733a84a1e426d2ca393da99f2d42168969402ecca7e  guix-build-6200fbf54fa9/output/riscv64-linux-gnu/SHA256SUMS.part
168ddd7ff09980c70002279e391450d80d0e49a4828a6a2647693d386068b6d0  guix-build-6200fbf54fa9/output/riscv64-linux-gnu/bitcoin-6200fbf54fa9-riscv64-linux-gnu-debug.tar.gz
a1adf8450dc4a5ca72b588081c355f9400286bd059664b1d6facb0ef33523b43  guix-build-6200fbf54fa9/output/riscv64-linux-gnu/bitcoin-6200fbf54fa9-riscv64-linux-gnu.tar.gz
78a663bbd7618b47dd84d0a729de55fab758246de4d400827450a3897df78a85  guix-build-6200fbf54fa9/output/x86_64-apple-darwin/SHA256SUMS.part
b7edf07f67492dde52b2b0da1e5e200d6f56ba91168b4e377f0c8f6589eb4358  guix-build-6200fbf54fa9/output/x86_64-apple-darwin/bitcoin-6200fbf54fa9-osx-unsigned.dmg
0f5dfab2ed141bc35f8d19e1c8832399695a122e9339637e40924c5847e05bab  guix-build-6200fbf54fa9/output/x86_64-apple-darwin/bitcoin-6200fbf54fa9-osx-unsigned.tar.gz
fe5aa2d9ce7b5f80b5a624b6613c577c8fd4d116bfccde8e0a00bd52e19db57e  guix-build-6200fbf54fa9/output/x86_64-apple-darwin/bitcoin-6200fbf54fa9-osx64.tar.gz
abedd8376c4fd0086f1cc699610d2adf926f991ad6fba437bb24949df3ae1320  guix-build-6200fbf54fa9/output/x86_64-linux-gnu/SHA256SUMS.part
52ccacc7e5a035355d253940aa3ea9e478b59178a2fcac2e0217028c0b817e3d  guix-build-6200fbf54fa9/output/x86_64-linux-gnu/bitcoin-6200fbf54fa9-x86_64-linux-gnu-debug.tar.gz
446ac535e043fb56164711f42ab78117713a901ce7a46a866b0f4f9da43f9b88  guix-build-6200fbf54fa9/output/x86_64-linux-gnu/bitcoin-6200fbf54fa9-x86_64-linux-gnu.tar.gz
e6a3980492b714430479d7803765294544999b50ef65df37d8648b240dc4bc26  guix-build-6200fbf54fa9/output/x86_64-w64-mingw32/SHA256SUMS.part
9c1c3652170a6217d8bea4b9241e8921f980c86ce85e3389371d5278612fb7c8  guix-build-6200fbf54fa9/output/x86_64-w64-mingw32/bitcoin-6200fbf54fa9-win-unsigned.tar.gz
42bfe4ba6570f8f524f0d6ae45f91cf18ef04e77fa19e0c07abd5ea7ce43b5e6  guix-build-6200fbf54fa9/output/x86_64-w64-mingw32/bitcoin-6200fbf54fa9-win64-debug.zip
225e5de0e161424da9506ba89b63aaaab2b5b7fe535aca3def68bebd1962e297  guix-build-6200fbf54fa9/output/x86_64-w64-mingw32/bitcoin-6200fbf54fa9-win64-setup-unsigned.exe
922cd070d5db7b83d81d9e2fb14248f555bc8dde917dde9b555f0cae9faa6c1c  guix-build-6200fbf54fa9/output/x86_64-w64-mingw32/bitcoin-6200fbf54fa9-win64.zip