Collect Ruby VM internal event metrics (object allocation)

[marcotc]

Motivation

We would like more visibility over the internal overhead of Ruby into our application execution.
It can be useful to know if a web request has created many more objects that all other requests in the same application, for example.

How

Ruby has internal events related to object lifecycle (NEWOBJ, FREEOBJ) that are broadcast to any registered internal tracepoint event listener.

Here are all the events available in Ruby 3.1.2:

#define RUBY_INTERNAL_EVENT_NEWOBJ          0x100000 /**< Object allocated. */
#define RUBY_INTERNAL_EVENT_FREEOBJ         0x200000 /**< Object swept. */
#define RUBY_INTERNAL_EVENT_GC_START        0x400000 /**< GC started. */
#define RUBY_INTERNAL_EVENT_GC_END_MARK     0x800000 /**< GC ended mark phase. */
#define RUBY_INTERNAL_EVENT_GC_END_SWEEP   0x1000000 /**< GC ended sweep phase. */
#define RUBY_INTERNAL_EVENT_GC_ENTER       0x2000000 /**< `gc_enter()` is called. */
#define RUBY_INTERNAL_EVENT_GC_EXIT        0x4000000 /**< `gc_exit()` is called. */

Here's how to register an internal tracepoint event listener:

    VALUE tpval = rb_tracepoint_new(0, RUBY_INTERNAL_EVENT_NEWOBJ | RUBY_INTERNAL_EVENT_FREEOBJ |
				    RUBY_INTERNAL_EVENT_GC_START | RUBY_INTERNAL_EVENT_GC_END_MARK |
				    RUBY_INTERNAL_EVENT_GC_END_SWEEP,
				    tracepoint_track_objspace_events_i, &track);

One detail to keep in mind is that despite TracePoint being a public Ruby class, it is not allowed to trace RUBY_INTERNAL_EVENT_* events. Some of these events are too high frequency (e.g. NEWOBJ would be too slow to trace with Ruby code) or happen at sensitive times (GC events don't play well with Ruby objects being allocated during GC), thus not available for Ruby callback tracing, only native tracing.

What should be done

We should create native tracepoints to collect object allocation (RUBY_INTERNAL_EVENT_NEWOBJ). These numbers should be collected on a per-thread basis, in order to reduce the noise and allow for measuring allocations on a single trace.

The number of allocations should be stored on the top-level span.
Another option is to store this number for every span: if the overhead is not significant, this provides more value and makes it easier to pinpoint which span is creating an excessive number of objects, for example.

Other considerations

As you can see above, we have GC internal events as well.
As tempting as they may seem to collect, because GC runs are global, we have enough information in the public GC.stat method to gather GC metrics. GC.stat should be used instead, unless we see value in collecting internal GC details like Mark and Sweep events.

[delner]

Nice write-up!

• My understanding was that tracepoint comes with significant performance cost, even on the C-level. What's your expectation on the overhead of this approach?
• Regarding where we put allocation numbers: is top-level span useful enough? (Is this too "zoomed out"?) How expensive/plausible would it be to decorate each span instead?
• How does the tracepoint event mechanically decorate the span in question? How does it retrieve the span? Does it have to access & increment the allocation count repeatedly?