Always debug heap recorder on stack recorder heap test failures

DataDog · Dec 20, 2023 · 643ee92 · 643ee92
1 parent d73978d
commit 643ee92
Show file tree

Hide file tree

Showing 4 changed files with 34 additions and 16 deletions.
diff --git a/ext/ddtrace_profiling_native_extension/heap_recorder.c b/ext/ddtrace_profiling_native_extension/heap_recorder.c
@@ -333,22 +333,34 @@ 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) {
+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)) {
-    return ST_CONTINUE;
+    rb_str_catf(debug_str, "object=<invalid>");
+  } else {
+    rb_str_catf(debug_str, "object=%+"PRIsVALUE, ref);
   }
 
-  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));
+  rb_str_catf(debug_str, "\n");
+
   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 heap_recorder_testonly_debug(heap_recorder *heap_recorder) {
+  if (heap_recorder == NULL) {
+    return rb_str_new2("NULL heap_recorder");
+  }
+
+  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;
 }
 
 // ==========================

diff --git 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
@@ -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
@@ -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