diff --git a/ext/ddtrace_profiling_native_extension/heap_recorder.c b/ext/ddtrace_profiling_native_extension/heap_recorder.c index 8578dda5715..6bcc2bc60de 100644 --- a/ext/ddtrace_profiling_native_extension/heap_recorder.c +++ b/ext/ddtrace_profiling_native_extension/heap_recorder.c @@ -136,6 +136,7 @@ static int st_heap_record_entry_free(st_data_t, st_data_t, st_data_t); static int st_object_record_entry_free(st_data_t, st_data_t, st_data_t); static int st_object_record_entry_free_if_invalid(st_data_t, st_data_t, st_data_t); static int st_object_records_iterate(st_data_t, st_data_t, st_data_t); +static int st_object_records_debug(st_data_t key, st_data_t value, st_data_t extra); static int update_object_record_entry(st_data_t*, st_data_t*, st_data_t, int); static void commit_allocation(heap_recorder*, heap_record*, long, live_object_data); @@ -333,22 +334,14 @@ void heap_recorder_testonly_assert_hash_matches(ddog_prof_Slice_Location locatio } } -int st_object_records_debug(DDTRACE_UNUSED st_data_t key, st_data_t value, DDTRACE_UNUSED st_data_t extra) { - object_record *record = (object_record*) value; - VALUE ref; - if (!ruby_ref_from_id(LONG2NUM(record->obj_id), &ref)) { - return ST_CONTINUE; +VALUE heap_recorder_testonly_debug(heap_recorder *heap_recorder) { + if (heap_recorder == NULL) { + return rb_str_new2("NULL heap_recorder"); } - heap_frame top_frame = record->heap_record->stack->frames[0]; - VALUE str = rb_sprintf("obj_id=%ld weight=%d location=%s:%d object=%+"PRIsVALUE, record->obj_id, record->object_data.weight, top_frame.filename, (int) top_frame.line, ref); - fprintf(stderr, "%s\n", RSTRING_PTR(str)); - return ST_CONTINUE; -} - -void heap_recorder_testonly_debug(heap_recorder *heap_recorder) { - fprintf(stderr, "object records:\n"); - st_foreach(heap_recorder->object_records, st_object_records_debug, (st_data_t) NULL); + VALUE debug_str = rb_str_new2("object records:\n"); + st_foreach(heap_recorder->object_records, st_object_records_debug, (st_data_t) debug_str); + return debug_str; } // ========================== @@ -417,6 +410,26 @@ static int st_object_records_iterate(DDTRACE_UNUSED st_data_t key, st_data_t val return ST_CONTINUE; } +static int st_object_records_debug(DDTRACE_UNUSED st_data_t key, st_data_t value, st_data_t extra) { + VALUE debug_str = (VALUE) extra; + + object_record *record = (object_record*) value; + + heap_frame top_frame = record->heap_record->stack->frames[0]; + rb_str_catf(debug_str, "obj_id=%ld weight=%d location=%s:%d ", record->obj_id, record->object_data.weight, top_frame.filename, (int) top_frame.line); + + VALUE ref; + if (!ruby_ref_from_id(LONG2NUM(record->obj_id), &ref)) { + rb_str_catf(debug_str, "object="); + } else { + rb_str_catf(debug_str, "object=%+"PRIsVALUE, ref); + } + + rb_str_catf(debug_str, "\n"); + + return ST_CONTINUE; +} + // Struct holding data required for an update operation on heap_records typedef struct { // [in] The new object record we want to add. diff --git a/ext/ddtrace_profiling_native_extension/heap_recorder.h b/ext/ddtrace_profiling_native_extension/heap_recorder.h index 96af08ea68b..27918c0f2cd 100644 --- a/ext/ddtrace_profiling_native_extension/heap_recorder.h +++ b/ext/ddtrace_profiling_native_extension/heap_recorder.h @@ -107,4 +107,6 @@ bool heap_recorder_for_each_live_object( // corresponding internal representations in heap recorder. void heap_recorder_testonly_assert_hash_matches(ddog_prof_Slice_Location locations); -void heap_recorder_testonly_debug(heap_recorder *heap_recorder); +// Returns a Ruby string with a representation of internal data helpful to +// troubleshoot issues such as unexpected test failures. +VALUE heap_recorder_testonly_debug(heap_recorder *heap_recorder); diff --git a/ext/ddtrace_profiling_native_extension/stack_recorder.c b/ext/ddtrace_profiling_native_extension/stack_recorder.c index f3ddc9e7328..a3398c343f5 100644 --- a/ext/ddtrace_profiling_native_extension/stack_recorder.c +++ b/ext/ddtrace_profiling_native_extension/stack_recorder.c @@ -850,7 +850,5 @@ static VALUE _native_debug_heap_recorder(DDTRACE_UNUSED VALUE _self, VALUE recor struct stack_recorder_state *state; TypedData_Get_Struct(recorder_instance, struct stack_recorder_state, &stack_recorder_typed_data, state); - heap_recorder_testonly_debug(state->heap_recorder); - - return Qnil; + return heap_recorder_testonly_debug(state->heap_recorder); } diff --git a/spec/datadog/profiling/stack_recorder_spec.rb b/spec/datadog/profiling/stack_recorder_spec.rb index 1954edb3fc5..116e06d01c8 100644 --- a/spec/datadog/profiling/stack_recorder_spec.rb +++ b/spec/datadog/profiling/stack_recorder_spec.rb @@ -387,6 +387,15 @@ def sample_allocation(obj) GC.start end + after do |example| + # This is here to facilitate troubleshooting when this test fails. Otherwise + # it's very hard to understand what may be happening. + if example.exception + puts('Heap recorder debugging info:') + puts(described_class::Testing._native_debug_heap_recorder(stack_recorder)) + end + end + context 'when disabled' do let(:heap_samples_enabled) { false } @@ -415,10 +424,7 @@ def sample_allocation(obj) sum_heap_samples = 0 heap_samples.each { |s| sum_heap_samples += s.values[:'heap-live-samples'] } - # FIXME: Remove, this is just for debugging purposes - described_class::Testing._native_debug_heap_recorder(stack_recorder) if sum_heap_samples != 150 - - expect(sum_heap_samples).to eq([a_string, an_array, a_hash].size * sample_rate) + expect(sum_heap_samples).to(eq([a_string, an_array, a_hash].size * sample_rate)) end it 'keeps on reporting accurate samples for other profile types' do