Skip to content

Commit

Permalink
Merge pull request #3620 from DataDog/ivoanjo/backport-pr3583
Browse files Browse the repository at this point in the history
Backport "[PROF-9472] Add recorder_stats and profile_stats to internal metadata" to 1.x-stable
  • Loading branch information
ivoanjo committed May 7, 2024
2 parents a592744 + d35e22c commit b96e01f
Show file tree
Hide file tree
Showing 10 changed files with 414 additions and 93 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -929,18 +929,6 @@ static VALUE _native_stats(DDTRACE_UNUSED VALUE self, VALUE instance) {
struct cpu_and_wall_time_worker_state *state;
TypedData_Get_Struct(instance, struct cpu_and_wall_time_worker_state, &cpu_and_wall_time_worker_typed_data, state);

VALUE pretty_cpu_sampling_time_ns_min = state->stats.cpu_sampling_time_ns_min == UINT64_MAX ? Qnil : ULL2NUM(state->stats.cpu_sampling_time_ns_min);
VALUE pretty_cpu_sampling_time_ns_max = state->stats.cpu_sampling_time_ns_max == 0 ? Qnil : ULL2NUM(state->stats.cpu_sampling_time_ns_max);
VALUE pretty_cpu_sampling_time_ns_total = state->stats.cpu_sampling_time_ns_total == 0 ? Qnil : ULL2NUM(state->stats.cpu_sampling_time_ns_total);
VALUE pretty_cpu_sampling_time_ns_avg =
state->stats.cpu_sampled == 0 ? Qnil : DBL2NUM(((double) state->stats.cpu_sampling_time_ns_total) / state->stats.cpu_sampled);

VALUE pretty_allocation_sampling_time_ns_min = state->stats.allocation_sampling_time_ns_min == UINT64_MAX ? Qnil : ULL2NUM(state->stats.allocation_sampling_time_ns_min);
VALUE pretty_allocation_sampling_time_ns_max = state->stats.allocation_sampling_time_ns_max == 0 ? Qnil : ULL2NUM(state->stats.allocation_sampling_time_ns_max);
VALUE pretty_allocation_sampling_time_ns_total = state->stats.allocation_sampling_time_ns_total == 0 ? Qnil : ULL2NUM(state->stats.allocation_sampling_time_ns_total);
VALUE pretty_allocation_sampling_time_ns_avg =
state->stats.allocation_sampled == 0 ? Qnil : DBL2NUM(((double) state->stats.allocation_sampling_time_ns_total) / state->stats.allocation_sampled);

unsigned long total_cpu_samples_attempted = state->stats.cpu_sampled + state->stats.cpu_skipped;
VALUE effective_cpu_sample_rate =
total_cpu_samples_attempted == 0 ? Qnil : DBL2NUM(((double) state->stats.cpu_sampled) / total_cpu_samples_attempted);
Expand Down Expand Up @@ -968,19 +956,19 @@ static VALUE _native_stats(DDTRACE_UNUSED VALUE self, VALUE instance) {
ID2SYM(rb_intern("cpu_sampled")), /* => */ UINT2NUM(state->stats.cpu_sampled),
ID2SYM(rb_intern("cpu_skipped")), /* => */ UINT2NUM(state->stats.cpu_skipped),
ID2SYM(rb_intern("cpu_effective_sample_rate")), /* => */ effective_cpu_sample_rate,
ID2SYM(rb_intern("cpu_sampling_time_ns_min")), /* => */ pretty_cpu_sampling_time_ns_min,
ID2SYM(rb_intern("cpu_sampling_time_ns_max")), /* => */ pretty_cpu_sampling_time_ns_max,
ID2SYM(rb_intern("cpu_sampling_time_ns_total")), /* => */ pretty_cpu_sampling_time_ns_total,
ID2SYM(rb_intern("cpu_sampling_time_ns_avg")), /* => */ pretty_cpu_sampling_time_ns_avg,
ID2SYM(rb_intern("cpu_sampling_time_ns_min")), /* => */ RUBY_NUM_OR_NIL(state->stats.cpu_sampling_time_ns_min, != UINT64_MAX, ULL2NUM),
ID2SYM(rb_intern("cpu_sampling_time_ns_max")), /* => */ RUBY_NUM_OR_NIL(state->stats.cpu_sampling_time_ns_max, > 0, ULL2NUM),
ID2SYM(rb_intern("cpu_sampling_time_ns_total")), /* => */ RUBY_NUM_OR_NIL(state->stats.cpu_sampling_time_ns_total, > 0, ULL2NUM),
ID2SYM(rb_intern("cpu_sampling_time_ns_avg")), /* => */ RUBY_AVG_OR_NIL(state->stats.cpu_sampling_time_ns_total, state->stats.cpu_sampled),

// Allocation stats
ID2SYM(rb_intern("allocation_sampled")), /* => */ state->allocation_profiling_enabled ? ULONG2NUM(state->stats.allocation_sampled) : Qnil,
ID2SYM(rb_intern("allocation_skipped")), /* => */ state->allocation_profiling_enabled ? ULONG2NUM(state->stats.allocation_skipped) : Qnil,
ID2SYM(rb_intern("allocation_effective_sample_rate")), /* => */ effective_allocation_sample_rate,
ID2SYM(rb_intern("allocation_sampling_time_ns_min")), /* => */ pretty_allocation_sampling_time_ns_min,
ID2SYM(rb_intern("allocation_sampling_time_ns_max")), /* => */ pretty_allocation_sampling_time_ns_max,
ID2SYM(rb_intern("allocation_sampling_time_ns_total")), /* => */ pretty_allocation_sampling_time_ns_total,
ID2SYM(rb_intern("allocation_sampling_time_ns_avg")), /* => */ pretty_allocation_sampling_time_ns_avg,
ID2SYM(rb_intern("allocation_sampling_time_ns_min")), /* => */ RUBY_NUM_OR_NIL(state->stats.allocation_sampling_time_ns_min, != UINT64_MAX, ULL2NUM),
ID2SYM(rb_intern("allocation_sampling_time_ns_max")), /* => */ RUBY_NUM_OR_NIL(state->stats.allocation_sampling_time_ns_max, > 0, ULL2NUM),
ID2SYM(rb_intern("allocation_sampling_time_ns_total")), /* => */ RUBY_NUM_OR_NIL(state->stats.allocation_sampling_time_ns_total, > 0, ULL2NUM),
ID2SYM(rb_intern("allocation_sampling_time_ns_avg")), /* => */ RUBY_AVG_OR_NIL(state->stats.allocation_sampling_time_ns_total, state->stats.allocation_sampled),
ID2SYM(rb_intern("allocation_sampler_snapshot")), /* => */ allocation_sampler_snapshot,
ID2SYM(rb_intern("allocations_during_sample")), /* => */ state->allocation_profiling_enabled ? UINT2NUM(state->stats.allocations_during_sample) : Qnil,
};
Expand Down
41 changes: 38 additions & 3 deletions ext/datadog_profiling_native_extension/heap_recorder.c
Original file line number Diff line number Diff line change
Expand Up @@ -158,6 +158,13 @@ struct heap_recorder {

// Sampling state
uint num_recordings_skipped;

struct stats_last_update {
size_t objects_alive;
size_t objects_dead;
size_t objects_skipped;
size_t objects_frozen;
} stats_last_update;
};
static heap_record* get_or_create_heap_record(heap_recorder*, ddog_prof_Slice_Location);
static void cleanup_heap_record_if_unused(heap_recorder*, heap_record*);
Expand Down Expand Up @@ -372,6 +379,9 @@ void heap_recorder_prepare_iteration(heap_recorder *heap_recorder) {
rb_raise(rb_eRuntimeError, "New heap recorder iteration prepared without the previous one having been finished.");
}

// Reset last update stats, we'll be building them from scratch during the st_foreach call below
heap_recorder->stats_last_update = (struct stats_last_update) {};

st_foreach(heap_recorder->object_records, st_object_record_update, (st_data_t) heap_recorder);

heap_recorder->object_records_snapshot = st_copy(heap_recorder->object_records);
Expand Down Expand Up @@ -427,6 +437,22 @@ bool heap_recorder_for_each_live_object(
return true;
}

VALUE heap_recorder_state_snapshot(heap_recorder *heap_recorder) {
VALUE arguments[] = {
ID2SYM(rb_intern("num_object_records")), /* => */ LONG2NUM(heap_recorder->object_records->num_entries),
ID2SYM(rb_intern("num_heap_records")), /* => */ LONG2NUM(heap_recorder->heap_records->num_entries),

// Stats as of last update
ID2SYM(rb_intern("last_update_objects_alive")), /* => */ LONG2NUM(heap_recorder->stats_last_update.objects_alive),
ID2SYM(rb_intern("last_update_objects_dead")), /* => */ LONG2NUM(heap_recorder->stats_last_update.objects_dead),
ID2SYM(rb_intern("last_update_objects_skipped")), /* => */ LONG2NUM(heap_recorder->stats_last_update.objects_skipped),
ID2SYM(rb_intern("last_update_objects_frozen")), /* => */ LONG2NUM(heap_recorder->stats_last_update.objects_frozen),
};
VALUE hash = rb_hash_new();
for (long unsigned int i = 0; i < VALUE_COUNT(arguments); i += 2) rb_hash_aset(hash, arguments[i], arguments[i+1]);
return hash;
}

void heap_recorder_testonly_assert_hash_matches(ddog_prof_Slice_Location locations) {
heap_stack *stack = heap_stack_new(locations);
heap_record_key stack_based_key = (heap_record_key) {
Expand Down Expand Up @@ -497,12 +523,14 @@ static int st_object_record_update(st_data_t key, st_data_t value, st_data_t ext
// no point checking for liveness or updating its size, so exit early.
// NOTE: This means that there should be an equivalent check during actual
// iteration otherwise we'd iterate/expose stale object data.
recorder->stats_last_update.objects_skipped++;
return ST_CONTINUE;
}

if (!ruby_ref_from_id(LONG2NUM(obj_id), &ref)) {
// Id no longer associated with a valid ref. Need to delete this object record!
on_committed_object_record_cleanup(recorder, record);
recorder->stats_last_update.objects_dead++;
return ST_DELETE;
}

Expand Down Expand Up @@ -537,6 +565,7 @@ static int st_object_record_update(st_data_t key, st_data_t value, st_data_t ext
RB_FL_SET(ref, RUBY_FL_SEEN_OBJ_ID);

on_committed_object_record_cleanup(recorder, record);
recorder->stats_last_update.objects_dead++;
return ST_DELETE;
}

Expand All @@ -550,6 +579,11 @@ static int st_object_record_update(st_data_t key, st_data_t value, st_data_t ext
record->object_data.is_frozen = RB_OBJ_FROZEN(ref);
}

recorder->stats_last_update.objects_alive++;
if (record->object_data.is_frozen) {
recorder->stats_last_update.objects_frozen++;
}

return ST_CONTINUE;
}

Expand Down Expand Up @@ -767,9 +801,10 @@ void object_record_free(object_record *record) {

VALUE object_record_inspect(object_record *record) {
heap_frame top_frame = record->heap_record->stack->frames[0];
VALUE inspect = rb_sprintf("obj_id=%ld weight=%d size=%zu location=%s:%d alloc_gen=%zu gen_age=%zu ",
record->obj_id, record->object_data.weight, record->object_data.size, top_frame.filename,
(int) top_frame.line, record->object_data.alloc_gen, record->object_data.gen_age);
live_object_data object_data = record->object_data;
VALUE inspect = rb_sprintf("obj_id=%ld weight=%d size=%zu location=%s:%d alloc_gen=%zu gen_age=%zu frozen=%d ",
record->obj_id, object_data.weight, object_data.size, top_frame.filename,
(int) top_frame.line, object_data.alloc_gen, object_data.gen_age, object_data.is_frozen);

const char *class = record->object_data.class;
if (class != NULL) {
Expand Down
5 changes: 5 additions & 0 deletions ext/datadog_profiling_native_extension/heap_recorder.h
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,11 @@ bool heap_recorder_for_each_live_object(
bool (*for_each_callback)(heap_recorder_iteration_data data, void* extra_arg),
void *for_each_callback_extra_arg);

// Return a Ruby hash containing a snapshot of this recorder's interesting state at calling time.
// WARN: This allocates in the Ruby VM and therefore should not be called without the
// VM lock or during GC.
VALUE heap_recorder_state_snapshot(heap_recorder *heap_recorder);

// v--- TEST-ONLY APIs ---v

// Assert internal hashing logic is valid for the provided locations and its
Expand Down
3 changes: 3 additions & 0 deletions ext/datadog_profiling_native_extension/ruby_helpers.h
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,9 @@ NORETURN(
#define ENFORCE_SUCCESS_HELPER(expression, have_gvl) \
{ int result_syserr_errno = expression; if (RB_UNLIKELY(result_syserr_errno)) raise_syserr(result_syserr_errno, have_gvl, ADD_QUOTES(expression), __FILE__, __LINE__, __func__); }

#define RUBY_NUM_OR_NIL(val, condition, conv) ((val condition) ? conv(val) : Qnil)
#define RUBY_AVG_OR_NIL(total, count) ((count == 0) ? Qnil : DBL2NUM(((double) total) / count))

// Called by ENFORCE_SUCCESS_HELPER; should not be used directly
NORETURN(void raise_syserr(
int syserr_errno,
Expand Down
Loading

0 comments on commit b96e01f

Please sign in to comment.