Hi there,

When I run the suggested steps in tests/programs/Dockerfile.server, rbperf errors out with

pid: 38686
libruby: /usr/local/lib/libruby.so.3.0.0 @ 0x7f54251d7000
ruby main thread address: 0x7f5425598138
process base address: 0x55b26e96f000
ruby version: "3.0.0"

Error: setup_perf_event failed with errno No such device

According to the perf_event_open(2) docs, this indicates that my CPU is missing a feature, but standard Linux perf can sample from that ruby process without problem.

My cpuinfo is attached in case it's helpful (AMD 5800X3D): cpuinfo.txt

I'm running kernel Linux CRAGNOR 6.0.9-arch1-1 #1 SMP PREEMPT_DYNAMIC Wed, 16 Nov 2022 17:01:17 +0000 x86_64 GNU/Linux

I'm not sure if it's a configuration issue (in which case I'll submit a PR for README.md) or some limitation of the way that rbperf is configuring the perf events.

rather than exiting without writing the profile

[2022-08-07T20:16:43Z DEBUG rbperf::rbperf] program type Tracepoint
^C[2022-08-07T20:16:49Z DEBUG rbperf::rbperf] Polling perfbuf failed with System(4)
Got 120 samples and 0 errors
Flamegraph written to: rbperf_flame_08072022_20h16m49s.svg

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

This is disabled by default as it's not fully implemented and the numbers might not be totally accurate unfortunately. Can be enabled with --enable-linenos

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

Tested with Ruby built with:

RUBY_CONFIGURE_OPTS="--disable-shared" rbenv install 3.0.4

$ cargo run record  -p 2529227 syscall enter_writev
pid: 2534079
statically linked
ruby main thread address: 0x5650b11eecb0
process base address: 0x5650b0df2000
ruby version: "3.0.4"

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

The overly complicated stack walking in two steps was implemented to try to pack as much work as possible per loop iteration to prevent the BPF verifier from rejecting our program due to the high complexity while analysing all the potential code paths, but I don't think this is needed anymore, so removing it to make the code vastly simpler!

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

Using rbspy's bindgen-generated structures for the ABI we rely on. There's some fields that we need that haven't been generated, so still hardcoding these for the time being

The xtask binary to generate the Ruby configuration is quite repetitive and could be improved by using macros at some point

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

cargo upgrade --incompatible

And updated the code. One of the most exciting changes is that this updates us to libbpf v1.0!

Test plan

$ cargo t
running 26 tests
test binary::tests::test_malformed_ruby_version_should_panic - should panic ... ok
test bindgen_test_layout_RubyFrame ... ok
test bindgen_test_layout_RubyVersionOffsets ... ok
test bindgen_test_layout_RubyStack ... ok
test bindgen_test_layout_RubyStackAddresses ... ok
test bindgen_test_layout_RubyStackAddress ... ok
test bindgen_test_layout_ProcessData ... ok
test bindgen_test_layout_SampleState ... ok
test binary::tests::test_find_main_works ... ok
test binary::tests::test_ruby_current_thread_does_not_exist ... ok
test rbperf::tests::test_verbose_bpf_logging_disabled ... ok
test ruby_readers::tests::test_parse_char_buffer_works ... ok
test ruby_readers::tests::test_parse_empty_char_buffer ... ok
test ruby_readers::tests::test_parse_malformed_char_buffer_errors ... ok
test ruby_readers::tests::test_parse_stack ... ok
test rbperf::tests::rbperf_test_3_0_0 ... ok
test rbperf::tests::rbperf_test_2_7_1 ... ok
test rbperf::tests::rbperf_test_2_7_4 ... ok
test rbperf::tests::test_ringbuf ... ok
test rbperf::tests::rbperf_test_2_6_3 ... ok
test rbperf::tests::rbperf_test_3_0_4 ... ok
test rbperf::tests::rbperf_test_2_7_6 ... ok
test rbperf::tests::rbperf_test_3_1_2 ... ok
test rbperf::tests::rbperf_test_2_6_0 ... ok
test rbperf::tests::test_cpu_profiling ... ok
test rbperf::tests::test_big_stack ... ok

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

Right now this is most useful as a troubleshooting tool. I am planning to use this information to choose between implementations, such as whether ring buffers can be used, so --ringbufdoesn't have to be specified in systems that support this more efficient API

[javierhonduco@fedora rbperf]$ cargo run info
   Compiling rbperf v0.1.0-beta (/home/javierhonduco/code/rbperf)
    Finished dev [unoptimized + debuginfo] target(s) in 7.90s
     Running `sudo -E target/debug/rbperf info`
System info
-----------
Kernel release: 5.18.13-200.fc36.x86_64
Debugfs mounted: true

BPF features
------------
is jited: true
has stats: true
has tail_call: true
has ringbuf: true
has bpf_loop: true

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

Process IDs (PIDs) are reused on Linux, so it's possible that we start profiling a Ruby process with some PID and later on, while still profiling, this process exits and a new one is spawned with this same PID.

The profiling information will be wrong. rbperf has some guardrails to help here, such as ensuring that method and path names are valid unicode, otherwise we consider the stack to be invalid, but it would be best to actively ensure we don't have a race condition here.

By using the pid + start_time of the process, we should be able to have a truly unique identifier of every process

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

• by abstracting the test process functionality
• adding on-CPU profiling tests
• testing the ringbuffer
• adding a test that doesn't run the BPF code in verbose mode

Signed-off-by: Francisco Javier Honduvilla Coto [email protected]

To ensure that all the below works fine:

• https://github.com/javierhonduco/rbperf/pull/27
  • Ring buffer
  • Perf buffers
  • CPU profiling
• Big stacks (https://github.com/javierhonduco/rbperf/commit/b474d3fa4a8a9b3bf8558134c43df928b5708454)

https://github.com/javierhonduco/rbperf/blob/28e2f524b2f97703ca8e975fd23128361f34217f/src/rbperf.rs#L436

p ((struct RString)(*((rb_control_frame_t*) (ruby_current_vm_ptr->ractor->main_thread->ec->vm_stack + ruby_current_vm_ptr->ractor->main_thread->ec->vm_stack_size) - 2).iseq.body.location.label)).as.heap.ptr

set *(0x7fd016296c42+2) = 0xf
set {char [10]} 0x7fd016296c42 = 0xf

Summary

This is a feature that several people have brought up. The idea would be to spawn a Ruby process directly and start profiling it. So instead of having to do this

# in one terminal or in the background
$ bundler run my_ruby_app
$ rbperf record --pid `pidof my_ruby_app` cpu

We could do

$ rbperf record --exec 'bundler run my_ruby_app' cpu

Possible implementation

This feature needs to control the execution of another process so the ptrace(2) system call is a good fit.

Something that this implementation might have to handle is the race condition between the moment when the process is executed and when all the libraries have been mapped in memory as there's a window when libruby, in the case of dynamically compiled CRuby, might not be mapped into memory yet, and we would have to fail to find the global data that rbperf needs to read

https://github.com/javierhonduco/rbperf/blob/48ce25b2db9e88553dfdf7d3136933ee580c2294/src/process.rs#L73-L76

rbperf has two components that ought to be analysed, the BPF stack walker, and all the userspace facilities to process the events sent by the BPF program that will be used to build the profiles.

The overhead of the userspace part can be measured with perf or with higher-level tools such as top or htop. Understanding the performance of the BPF program would be very interesting, but unfortunately, the readily available metrics aren't representative.

For example, bpftool can show the avg runtime for BPF programs as well as how many times they've run. As the Ruby stack walker has a very fast path when the program running isn't profiled and a slower path, when it has to walk the stack, having only average biases the result and doesn't give us the complete picture

[javierhonduco@fedora rbperf]$ sudo sysctl -w kernel.bpf_stats_enabled=1
kernel.bpf_stats_enabled = 1
[javierhonduco@fedora rbperf]$ sudo bpftool prog  show id 763
763: perf_event  name on_event  tag 97fe3cd3a6716fe2  gpl run_time_ns 61692489 run_cnt 54968
        loaded_at 2022-10-30T19:05:51+0000  uid 0
        xlated 1520B  jited 1009B  memlock 4096B  map_ids 1021,1025,1018,1017,1019
        btf_id 844
        pids rbperf(532862)

Having the distribution of the run time of the BPF program would be ideal. I am planning to work on a tool to get this data to get a more accurate understanding of the actual performance impact of running rbperf

Some of the things I have planned:

• UX
  • [x] Better error handling (e.g. when providing a wrong syscall tracepoint name, we don't handle that nicely and the UX is bad) (https://github.com/javierhonduco/rbperf/commit/2abb8c0c49ad6e6ad1f6fa6f600fea95da5c3c62)
  • [x] Allow running tests and whatnot with cargo (https://github.com/javierhonduco/rbperf/commit/7c14cd0328f339ac6b9bf337f436d2c11970e2ca)
  • [x] Add info subcommand to show environmental details that might affect rbperf to aid debugging (https://github.com/javierhonduco/rbperf/commit/e81748a3861723e8891c28836467e147afbe2e8f)
• Quality
  • [x] Add tests for C data structure parsing and "serialisation". Run valgrind / asan on them, too (https://github.com/javierhonduco/rbperf/commit/2e3d1c017be1082395e2819955aa0ecae65818da)
  • [x] Compile BPF code with warnings on (https://github.com/javierhonduco/rbperf/commit/cb0e7b4be6e9c3ad433ddd1bfb78eee8bbf21a1b)
  • [x] Gather error statistics (right now they are mixed / not well categorised, e.g. a map can fail to write in kernel or to read from in userspace) (https://github.com/javierhonduco/rbperf/commit/4de5dee16e3ad68304057bb52e7c6cc5e09b14c8)
  • [x] Upstream elfutils and zlib static linking patches (https://github.com/libbpf/libbpf-sys/commit/371a85d2b453b6998bc91a09bb5f43ff45e521eb, https://github.com/libbpf/libbpf-rs/commit/5bed52a25fba063c871499c54a5ffab63d32dd08)
  • [x] Add tests for big stacks that require BPF tail-calls (https://github.com/javierhonduco/rbperf/commit/b474d3fa4a8a9b3bf8558134c43df928b5708454)
  • [x] Address PID reuse race condition: ( https://github.com/javierhonduco/rbperf/commit/272c8f3087b9f85c092ffccfbd131088e6b7d21d)
  • [ ] Verify that frames that we think are native are indeed native frames (https://github.com/javierhonduco/rbperf/blob/422c5ca6ffd0d7693/src/bpf/rbperf.bpf.c#L235)
• BPF
  • [x] Logging is enabled by default in the BPF program. This has high overhead and it is not needed most of the time (https://github.com/javierhonduco/rbperf/commit/422c5ca6ffd0d7693106b415d1daa742f84dcbc7)
  • [ ] Evaluate using ring buffers
    • [x] Add it as opt-in (https://github.com/javierhonduco/rbperf/commit/8a1e048b0684f0b8d89b87e9b9d3e7b7e6f8425f)
    • [ ] Run some tests to see how it behaviour compares to perf buffers
• Docs
  • Add a document on architecture, as well as in-depth comments in the BPF code
  • How to debug issues
  • How to add support for Ruby versions

• New features
  • Binary disk format
  • More output formats (folded stacks, chrome tracing, raw?)
  • Ensure it works in arm64
  • C function tracing, both from cruby or the libraries it dynamically links to (uprobes)

• Experimental ideas
  • Allocation tracing (w/ mem leak detection)
  • Request-specific data

• Other
  • [x] Ensure we work with YJIT (asked in https://github.com/Shopify/yjit/. It works so far, but this might change)
  • [ ] Add git revision to the future info subcommand and in the BPF's metadata section

• Release
  • Publish x86_64 binaries

Simplify execution context fetching:

(gdb) p/x ruby_current_vm_ptr->ractor->main_thread->ec
$1 = 0x20729b0
(gdb) p/x ruby_current_ec
$2 = 0x20729b0