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

build: add systemtap's sys/sdt.h as depends for GUIX builds with USDT tracepoints #23724

Merged
merged 2 commits into from Jan 10, 2022

Conversation

0xB10C
Copy link
Contributor

@0xB10C 0xB10C commented Dec 9, 2021

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. Binaries don't have to be switched out. This is possible because we don't do expensive computations only needed for the tracepoints. The tracepoints are NOPs when not used.

Systemtap's sys/sdt.h header is required to build Bitcoin Core with USDT support. The header file defines the DTRACE_PROBE macros used in src/util/trace.h. This PR adds Systemtap 4.5 (May 2021) as dependency. GUIX builds for Linux hosts now include the tracepoints.

Closes #23297.

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 9, 2021

Additional information that may be relevant for reviewers:

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!

platform binary contains tracepoints synced signet tracepoints tested and working
aarch64-linux-gnu ✔️ ✔️ ✔️
arm-linux-gnueabihf ✔️ ✔️ ❕¹
powerpc64-linux-gnu ✔️
powerpc64le-linux-gnu ✔️
riscv64-linux-gnu ✔️ ✔️ (laanwj) ❕ (laanwj)
x86_64-linux-gnu ✔️ ✔️ ✔️
x86_64-apple-darwin19 - ² -
x86_64-w64-mingw32 - ✔️ -

¹ 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

@laanwj
Copy link
Member

laanwj commented Dec 9, 2021

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

@DrahtBot
Copy link
Contributor

DrahtBot commented Dec 10, 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:

  • #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.

@laanwj
Copy link
Member

laanwj commented Dec 13, 2021

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?

@jb55
Copy link
Contributor

jb55 commented Dec 13, 2021

Concept ACK, will test soon

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 13, 2021

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!

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 13, 2021

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

@laanwj
Copy link
Member

laanwj commented Dec 14, 2021

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.

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 14, 2021

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.

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 14, 2021

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).

@laanwj
Copy link
Member

laanwj commented Dec 15, 2021

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

@ccdle12
Copy link
Contributor

ccdle12 commented Dec 15, 2021

Concept ACK, running the guix build

@ccdle12
Copy link
Contributor

ccdle12 commented Dec 15, 2021

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)

Copy link
Member

@fanquake fanquake left a comment

Choose a reason for hiding this comment

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

Concept ACK on adding tracepoints to the release builds, assuming there is 0 overhead for users who don't care about them. I think they should only be use for Linux for now. macOS support isn't as straightforward as Linux, and it's not clear to me if these are even a thing on Windows.

Guix build:

bash-5.1# find guix-build-$(git rev-parse --short=12 HEAD)/output/ -type f -print0 | env LC_ALL=C sort -z | xargs -r0 sha256sum
34bbefa86359e60b815552bb61d5e947eb6eaff5ab942b0415c9cdc0dad187b6  guix-build-070570806404/output/aarch64-linux-gnu/SHA256SUMS.part
48d6dcde292965cf81aa52d6f55c45e5b73281b863382c1f0aeae23ab4c10394  guix-build-070570806404/output/aarch64-linux-gnu/bitcoin-070570806404-aarch64-linux-gnu-debug.tar.gz
c72b18b090fc72d7fbf50bb41d6289ec71d234513102a96ecfaa8aa6003f7855  guix-build-070570806404/output/aarch64-linux-gnu/bitcoin-070570806404-aarch64-linux-gnu.tar.gz
c98a0b60b26fae5cf8b57212a70a160c8e9f8fc1756039bcaabeb833e921a414  guix-build-070570806404/output/arm-linux-gnueabihf/SHA256SUMS.part
cbddd5bdcbc9eebab5aafdf3267c89badc1d3acf19f8e9cb1fb0dba5a83a86c9  guix-build-070570806404/output/arm-linux-gnueabihf/bitcoin-070570806404-arm-linux-gnueabihf-debug.tar.gz
b465dffd7149f9f02c9255a0a5befec005c0b552bddbee40fbddfd2b0ca9d4e6  guix-build-070570806404/output/arm-linux-gnueabihf/bitcoin-070570806404-arm-linux-gnueabihf.tar.gz
e7a68186bf3d37e2c2134ae11a465f21f0b9d5d3233380e85bfd5c9eda043992  guix-build-070570806404/output/dist-archive/bitcoin-070570806404.tar.gz
17b0190a61345c7b6c7fd058bdf13ec9f50bab6eb4c0302c131a9b07a5c4433a  guix-build-070570806404/output/powerpc64-linux-gnu/SHA256SUMS.part
9d2c24eddceb5a88caa8372dfd1c306bde0266edaa01aa101da4dcd089ce9d41  guix-build-070570806404/output/powerpc64-linux-gnu/bitcoin-070570806404-powerpc64-linux-gnu-debug.tar.gz
cf0d5cd27c514b639eb22e577863a0ecf8bd45336522936eabfc9fa3963bab65  guix-build-070570806404/output/powerpc64-linux-gnu/bitcoin-070570806404-powerpc64-linux-gnu.tar.gz
af2930854be42d18f52787091fe4b796995b2cadec27a11262bbf5bcc284a869  guix-build-070570806404/output/powerpc64le-linux-gnu/SHA256SUMS.part
5b307c9cf5032ded0c11586f0533ce404dda93f7edc136260f5e4fdeeabd5442  guix-build-070570806404/output/powerpc64le-linux-gnu/bitcoin-070570806404-powerpc64le-linux-gnu-debug.tar.gz
6fe051d7b241b3c3d57f4c4ad40290b79eb4561d2abd4af110d1caefb5d0e3d3  guix-build-070570806404/output/powerpc64le-linux-gnu/bitcoin-070570806404-powerpc64le-linux-gnu.tar.gz
4b1c765f7a0c0110f51eb2ea80f974c0803654440f4dd22f5b5dee69f4429e89  guix-build-070570806404/output/riscv64-linux-gnu/SHA256SUMS.part
65454fe4048692e9eec35d06b6809a6f28fef9dbb9b1fc6eed734f6077c260ef  guix-build-070570806404/output/riscv64-linux-gnu/bitcoin-070570806404-riscv64-linux-gnu-debug.tar.gz
87c08928fd01eed62b4d68a1309cbb8c0943a655b169451cfb97e4911532270a  guix-build-070570806404/output/riscv64-linux-gnu/bitcoin-070570806404-riscv64-linux-gnu.tar.gz
05a3dd5516e4fc744b07d3342bc385ad0197ea5e7028783e6b156fddf0defebc  guix-build-070570806404/output/x86_64-apple-darwin/SHA256SUMS.part
5683bec557166c36d44dfccdf7c627952bde300a4a35ec4f63197513bffc0b9e  guix-build-070570806404/output/x86_64-apple-darwin/bitcoin-070570806404-osx-unsigned.dmg
6cb290ddf4e2b15404a2da9af160523c72d74e428ccc367e73c8ccbf111a0fe0  guix-build-070570806404/output/x86_64-apple-darwin/bitcoin-070570806404-osx-unsigned.tar.gz
5a7d3ad1643789dcda1329440238d236bf497599ba423ca686ab08fd63149c62  guix-build-070570806404/output/x86_64-apple-darwin/bitcoin-070570806404-osx64.tar.gz
b03af7a9654d852a3d65e0c4968dd6ebcc16587f10ac4c6bc59d6ee1ae9763b0  guix-build-070570806404/output/x86_64-linux-gnu/SHA256SUMS.part
fe9ecd853fa7bbe9d9896bf4b66c451eb47aa6b11d37643d52ea529e44007b3c  guix-build-070570806404/output/x86_64-linux-gnu/bitcoin-070570806404-x86_64-linux-gnu-debug.tar.gz
3bbf38305cfff63765f39675cea5e27c2dc3590ec6f54e07e18372e8953468c8  guix-build-070570806404/output/x86_64-linux-gnu/bitcoin-070570806404-x86_64-linux-gnu.tar.gz
7959f8df5702f5d68a57acdbd8b51c49fe9adc2c2a85fec0d8f10e3b9c78b7a9  guix-build-070570806404/output/x86_64-w64-mingw32/SHA256SUMS.part
28a7a7d8253f07d4109a33e5d7eb8725be50d6255ab42fc398b239b655efc463  guix-build-070570806404/output/x86_64-w64-mingw32/bitcoin-070570806404-win-unsigned.tar.gz
805150f60152a39220f7c8c4ce0f2bd3950d03c0c9320ff931b3ba1e807f8be7  guix-build-070570806404/output/x86_64-w64-mingw32/bitcoin-070570806404-win64-debug.zip
72b5edabde57d23dde1be60fbc95b3c35df0788bab11583002233c39953500f4  guix-build-070570806404/output/x86_64-w64-mingw32/bitcoin-070570806404-win64-setup-unsigned.exe
95d631b9bf70c45374f1a756257ef676ceec8553906a2876cd3e2c004d6e3a39  guix-build-070570806404/output/x86_64-w64-mingw32/bitcoin-070570806404-win64.zip

depends/packages/systemtap.mk Outdated Show resolved Hide resolved
depends/packages/packages.mk Outdated Show resolved Hide resolved
depends/packages/systemtap.mk Outdated Show resolved Hide resolved
@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 17, 2021

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:

bitcoin/src/net_processing.cpp

Lines 4141 to 4152 in 767c012

CNetMessage& msg(msgs.front());
TRACE6(net, inbound_message,
pfrom->GetId(),
pfrom->m_addr_name.c_str(),
pfrom->ConnectionTypeAsString().c_str(),
msg.m_command.c_str(),
msg.m_recv.size(),
msg.m_recv.data()
);
if (gArgs.GetBoolArg("-capturemessages", false)) {

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):

Binary with tracepoints

(I'm not sure why the first record includes 469 instructions.)

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
Binary without tracepoints
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).

@jb55
Copy link
Contributor

jb55 commented Dec 17, 2021

@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?

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 17, 2021

@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)

@jb55
Copy link
Contributor

jb55 commented Dec 17, 2021

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).

@jb55
Copy link
Contributor

jb55 commented Dec 17, 2021

@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 :(

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 18, 2021

@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.

jb55 added a commit to jb55/bitcoin that referenced this pull request Dec 18, 2021
In the net:inbound_message tracepoint, we are calling the
ConnectionTypeAsString helper function that converts the enum to a
string. This has been shown to generate quite a few instructions, even
when there is no code hooked into the tracepoint.

Here's the output from gdb when tracing the number of instructions
between two breakpoints around this tracepoint (see [1] for how to do
this):

	Recorded 293 instructions in 27 functions

Tracepoints should be almost zero cost, 293 instructions is a bit much
for effectively doing nothing most of the time.

Instead of calling the ConnectionTypeAsString function, simply add a
ConnectionType getter that returns the connection type enum directly.
This way the tracepoint simplifies to nine instructions that load values
into registers in preparation for a tracepoint call, which may or may
not be there depending on if there are any attached ebpf programs.

With this patch applied:

	Recorded 9 instructions in 1 functions

Signed-off-by: William Casarin <jb55@jb55.com>

[1] bitcoin#23724 (comment)
jb55 added a commit to jb55/bitcoin that referenced this pull request Dec 18, 2021
In the net:{inbound,outbound}_message tracepoint, we are calling the
ConnectionTypeAsString helper function that converts the enum to a
string. This has been shown to generate quite a few instructions, even
when there is no code hooked into the tracepoint.

Here's the output from gdb when tracing the number of instructions
between two breakpoints around this tracepoint (see [1] for how to do
this):

	Recorded 293 instructions in 27 functions

Tracepoints should be almost zero cost, 293 instructions is a bit much
for effectively doing nothing most of the time.

Instead of calling the ConnectionTypeAsString function, simply add a
ConnectionType getter that returns the connection type enum directly.
This way the tracepoint simplifies to nine instructions that load values
into registers in preparation for a tracepoint call, which may or may
not be there depending on if there are any attached ebpf programs.

With this patch applied:

	Recorded 9 instructions in 1 functions

Signed-off-by: William Casarin <jb55@jb55.com>

[1] bitcoin#23724 (comment)
jb55 added a commit to jb55/bitcoin that referenced this pull request Dec 18, 2021
In the net:{inbound,outbound}_message tracepoint, we are calling the
ConnectionTypeAsString helper function that converts the enum to a
string. This has been shown to generate quite a few instructions, even
when there is no code hooked into the tracepoint.

Here's the output from gdb when tracing the number of instructions
between two breakpoints around this tracepoint (see [1] for how to do
this):

	Recorded 293 instructions in 27 functions

Tracepoints should be almost zero cost, 293 instructions is a bit much
for effectively doing nothing most of the time.

Instead of calling the ConnectionTypeAsString function, simply add a
ConnectionType getter that returns the connection type enum directly.
This way the tracepoint simplifies to nine instructions that load values
into registers in preparation for a tracepoint call, which may or may
not be there depending on if there are any attached ebpf programs.

With this patch applied:

	Recorded 9 instructions in 1 functions

This tightens up these tracepoints in preparation for enabling tracing
in release builds[2].

Signed-off-by: William Casarin <jb55@jb55.com>

[1] bitcoin#23724 (comment)
[2] bitcoin#23724
@jb55
Copy link
Contributor

jb55 commented Dec 18, 2021

@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

jb55 added a commit to jb55/bitcoin that referenced this pull request Dec 18, 2021
In the net:{inbound,outbound}_message tracepoint, we are calling the
ConnectionTypeAsString helper function that converts the enum to a
string. This has been shown to generate quite a few instructions, even
when there is no code hooked into the tracepoint.

Here's the output from gdb when tracing the number of instructions
between two breakpoints around this tracepoint (see [1] for how to do
this):

	Recorded 293 instructions in 27 functions

Tracepoints should be almost zero cost, 293 instructions is a bit much
for effectively doing nothing most of the time.

Instead of calling the ConnectionTypeAsString function, simply add a
ConnectionType getter that returns the connection type enum directly.
This way the tracepoint simplifies to nine instructions that load values
into registers in preparation for a tracepoint call, which may or may
not be there depending on if there are any attached ebpf programs.

With this patch applied:

	Recorded 9 instructions in 1 functions

This tightens up these tracepoints in preparation for enabling tracing
in release builds[2].

Signed-off-by: William Casarin <jb55@jb55.com>

[1] bitcoin#23724 (comment)
[2] bitcoin#23724
@laanwj
Copy link
Member

laanwj commented Dec 18, 2021

-        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.

@0xB10C
Copy link
Contributor Author

0xB10C commented Dec 18, 2021

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.

bitcoin/src/validation.cpp

Lines 2160 to 2167 in cb27d60

TRACE6(validation, block_connected,
block.GetHash().data(),
pindex->nHeight,
block.vtx.size(),
nInputs,
nSigOpsCost,
GetTimeMicros() - nTimeStart // in microseconds (µs)
);

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.

bitcoin/src/validation.cpp

Lines 2328 to 2334 in cb27d60

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);

@jb55
Copy link
Contributor

jb55 commented Dec 18, 2021 via email

@laanwj
Copy link
Member

laanwj commented Dec 19, 2021

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!

@jb55
Copy link
Contributor

jb55 commented Dec 19, 2021 via email

@jb55
Copy link
Contributor

jb55 commented Dec 19, 2021 via email

@fanquake
Copy link
Member

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.

The sys/sdt.h header is required to build Bitcoin Core with Userspace
Statically Defined Tracing support. Systemtap version 4.5 (May 2021)
is used as the most recent version 4.6 (Nov 2021) fails to build.
See e.g. https://sourceware.org/git/?p=systemtap.git;a=commit;h=1d3653936fc1fd13135a723a27e6c7e959793ad0

As Systemtap itself is not needed, the build steps (configure and
make) are skipped. We require fewer build dependecies and don't
waste time building depends we don't end up using. However, the
configure step would normally processes sys/sdt-config.h.in. The
resulting sdt-config.h defines _SDT_ASM_SECTION_AUTOGROUP_SUPPORT
(either 0 or 1 to indicate whether the assembler supports "?" in
.pushsection directives). For now, we assume all currently used
assemblers supports this feature and remove the check from the
sys/sdt.h header file in a patch.

Co-authored-by: Michael Ford <fanquake@gmail.com>
@0xB10C
Copy link
Contributor Author

0xB10C commented Jan 4, 2022

@fanquake
Copy link
Member

fanquake commented Jan 6, 2022

Thanks, rebased.

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

eBPF is a Linux kernel technology used to "extend the capabilities
of the kernel without requiring to change kernel source code or
load kernel modules". While Userspace, Statically Defined Tracing
(USDT) uses eBPF under the hood, --enable-usdt better resembles that
support for USDT is enabled, and tracepoints will be included in the
binary.
@0xB10C
Copy link
Contributor Author

0xB10C commented Jan 6, 2022

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

Done, thanks!

Running a GUIX build now.

@0xB10C
Copy link
Contributor Author

0xB10C commented Jan 9, 2022

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

Copy link
Member

@fanquake fanquake left a comment

Choose a reason for hiding this comment

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

ACK 6200fbf - tested enabling / disabling and with/without SDT from depends. We can follow up with #23819, #23907 and #23296, and if any serious issues arise before feature freeze, it is easy for us to flip depends such that USDT becomes opt-in, rather than opt-out, and thus, releases would be tracepoint free.

Guix build also matched:

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

@fanquake fanquake merged commit 542e405 into bitcoin:master Jan 10, 2022
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Jan 10, 2022
…GUIX builds with USDT tracepoints

6200fbf build: rename --enable-ebpf to --enable-usdt (0xb10c)
e158a2a build: add systemtap's sys/sdt.h as depends (0xb10c)

Pull request description:

  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. Binaries don't have to be switched out. This is possible because we don't do [expensive computations](https://github.com/bitcoin/bitcoin/blob/master/doc/tracing.md#no-expensive-computations-for-tracepoints) only needed for the tracepoints. The tracepoints are NOPs when not used.

  Systemtap's `sys/sdt.h` header is required to build Bitcoin Core with USDT support. The header file defines the `DTRACE_PROBE` macros used in [`src/util/trace.h`](https://github.com/bitcoin/bitcoin/blob/master/src/util/trace.h). This PR adds Systemtap 4.5 (May 2021) as dependency. GUIX builds for Linux hosts now include the tracepoints.

  Closes bitcoin#23297.

ACKs for top commit:
  fanquake:
    ACK 6200fbf - tested enabling / disabling and with/without SDT from depends. We can follow up with bitcoin#23819, bitcoin#23907 and bitcoin#23296, and if any serious issues arise before feature freeze, it is easy for us to flip depends such that USDT becomes opt-in, rather than opt-out, and thus, releases would be tracepoint free.

Tree-SHA512: 0263f44892bf8450e8a593e4de7a498243687f8d81269e1c3283fa8354922c7cf93fddef4b92cf5192d33798424aa5812e03e68ef8de31af078a32dd34021382
@0xB10C 0xB10C deleted the 2021-12-usdt-depends branch January 17, 2022 09:53
@bitcoin bitcoin locked and limited conversation to collaborators Jan 17, 2023
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.

tracing: include tracepoints in GUIX builds
6 participants