diff --git a/ext/fiber/profiler/capture.c b/ext/fiber/profiler/capture.c index 814f5f1..bbd418b 100644 --- a/ext/fiber/profiler/capture.c +++ b/ext/fiber/profiler/capture.c @@ -627,6 +627,29 @@ static size_t Fiber_Profiler_Capture_absolute_nesting(struct Fiber_Profiler_Capt // If a call is within this threshold of the parent call, it will be skipped when printing the call stack - it's considered inconsequential to the performance of the parent call. static const double Fiber_Profiler_Capture_SKIP_THRESHOLD = 0.98; +static VALUE Fiber_Profiler_Capture_class_label(VALUE klass) { + // Included modules are represented by hidden ICLASS objects: + if (RB_TYPE_P(klass, T_ICLASS)) { + klass = RBASIC_CLASS(klass); + } + + if (RB_TYPE_P(klass, T_CLASS) || RB_TYPE_P(klass, T_MODULE)) { + // Hidden classes/modules cannot be inspected, but `rb_class_path` reads their path directly: + if (!RBASIC_CLASS(klass)) { + VALUE path = rb_class_path(klass); + + if (RB_TYPE_P(path, T_STRING)) return path; + + return rb_str_new_cstr(RB_TYPE_P(klass, T_CLASS) ? "" : ""); + } + + // Preserve `rb_inspect` formatting for visible classes, especially singleton classes: + return rb_inspect(klass); + } + + return rb_str_new_cstr(""); +} + void Fiber_Profiler_Capture_print_tty(struct Fiber_Profiler_Capture *capture, FILE *restrict stream, double duration) { double start_time = Fiber_Profiler_Time_delta(&capture->start_time, &capture->switch_time); @@ -677,13 +700,13 @@ void Fiber_Profiler_Capture_print_tty(struct Fiber_Profiler_Capture *capture, FI fprintf(stream, "\e[31m"); } - VALUE class_inspect = rb_inspect(call->klass); + VALUE class_label = Fiber_Profiler_Capture_class_label(call->klass); const char *name = rb_id2name(call->id); struct timespec offset; Fiber_Profiler_Time_elapsed(&capture->switch_time, &call->enter_time, &offset); - fprintf(stream, "%s:%d in %s '%s#%s' (%0.4fs, T+" Fiber_Profiler_TIME_PRINTF_TIMESPEC ")\n", call->path, call->line, event_flag_name(call->event_flag), RSTRING_PTR(class_inspect), name, call->duration, Fiber_Profiler_TIME_PRINTF_TIMESPEC_ARGUMENTS(offset)); + fprintf(stream, "%s:%d in %s '%s#%s' (%0.4fs, T+" Fiber_Profiler_TIME_PRINTF_TIMESPEC ")\n", call->path, call->line, event_flag_name(call->event_flag), RSTRING_PTR(class_label), name, call->duration, Fiber_Profiler_TIME_PRINTF_TIMESPEC_ARGUMENTS(offset)); fprintf(stream, "\e[0m"); @@ -731,7 +754,7 @@ void Fiber_Profiler_Capture_print_json(struct Fiber_Profiler_Capture *capture, F call->nesting = call->parent->nesting + 1; } - VALUE class_inspect = rb_inspect(call->klass); + VALUE class_label = Fiber_Profiler_Capture_class_label(call->klass); const char *name = rb_id2name(call->id); size_t nesting = Fiber_Profiler_Capture_absolute_nesting(capture, call); @@ -739,7 +762,7 @@ void Fiber_Profiler_Capture_print_json(struct Fiber_Profiler_Capture *capture, F struct timespec offset; Fiber_Profiler_Time_elapsed(&capture->switch_time, &call->enter_time, &offset); - fprintf(stream, "%s{\"path\":\"%s\",\"line\":%d,\"class\":\"%s\",\"method\":\"%s\",\"duration\":%0.6f,\"offset\":" Fiber_Profiler_TIME_PRINTF_TIMESPEC ",\"nesting\":%zu,\"skipped\":%zu,\"filtered\":%zu}", first ? "" : ",", call->path, call->line, RSTRING_PTR(class_inspect), name, call->duration, Fiber_Profiler_TIME_PRINTF_TIMESPEC_ARGUMENTS(offset), nesting, skipped, call->filtered); + fprintf(stream, "%s{\"path\":\"%s\",\"line\":%d,\"class\":\"%s\",\"method\":\"%s\",\"duration\":%0.6f,\"offset\":" Fiber_Profiler_TIME_PRINTF_TIMESPEC ",\"nesting\":%zu,\"skipped\":%zu,\"filtered\":%zu}", first ? "" : ",", call->path, call->line, RSTRING_PTR(class_label), name, call->duration, Fiber_Profiler_TIME_PRINTF_TIMESPEC_ARGUMENTS(offset), nesting, skipped, call->filtered); skipped = 0; first = 0; diff --git a/test/fiber/profiler/capture.rb b/test/fiber/profiler/capture.rb index 3b20f72..1fb915d 100644 --- a/test/fiber/profiler/capture.rb +++ b/test/fiber/profiler/capture.rb @@ -140,6 +140,51 @@ def nested(n = 100, &block) end end + with "hidden classes" do + let(:capture) {subject.new(stall_threshold: 0, filter_threshold: 0, output: output)} + + it "can report garbage collection inside methods of hidden classes" do + capture.start + + Fiber.new do + GC.stress = true + + # Lambda literals call a method on the hidden singleton class of RubyVM::FrozenCore: + ->{} + ensure + GC.stress = false + end.resume + + capture.stop + + stall = JSON.parse(output.string) + calls = stall["calls"] + expect(calls).to have_value(have_keys( + "class" => be =~ /\A#\z/, + "method" => be == "lambda", + )) + end + end + + with "singleton classes" do + it "reports the singleton class by name" do + capture.start + + Fiber.new do + Kernel.sleep 0.001 + end.resume + + capture.stop + + stall = JSON.parse(output.string) + calls = stall["calls"] + expect(calls).to have_value(have_keys( + "class" => be == "#", + "method" => be == "sleep", + )) + end + end + with "Process.fork" do it "should disable the profiler in the child process after fork" do capture.start