Add opt-in Ractor-local GC metrics to the Ractor harness

README.md

@@ -300,6 +300,46 @@ For reference, the JSON output also keeps `rss`, a single snapshot taken after a
 full GC at the end of the run (the retained set, a lower bound), and `maxrss`, the
 process's lifetime peak from `getrusage`.
 
+## Measuring Ractor GC activity
+
+The `--ractor-gc` option of `run_benchmarks.rb` collects Ractor-local GC
+metrics for benchmarks that use the Ractor harness (`--category ractor`).
+The target must use Ruby 4.1 or newer; older targets fail before warmup.
+
+```sh
+./run_benchmarks.rb --category ractor --chruby=base::ruby-base --ractor-gc
+```
+
+Each measured iteration samples `GC.stat` and GC total time in every worker
+Ractor's own object space. The JSON output records the scope as
+`gc_scope: "ractor-local-workload"`, `gc_stat_scope: "ractor-local"`, and
+`gc_measure_total_time_scope: "ractor-local"`, plus the target's `gc_config`.
+
+The summary table adds these columns:
+
+* `(worker sum)` columns add the Ractor-local counters of the sampled
+  workers of each iteration. Single-executable reports also show
+  `GC ms/worker`, which divides each iteration's worker-sum GC time by its
+  sampled worker count, then averages.
+* `global GCs/iter*` shows `GC.stat(:global_gc_count)` deltas observed by the
+  measuring main Ractor. These count stop-the-world global GC cycles, not
+  the process-wide total of all Ractors' local and global collections.
+  Stop-the-world cycles only exist once a second Ractor has been alive, so
+  count-0 rows read 0.0 unless the workload itself creates Ractors. In
+  comparison reports the same metric appears as `global/iter ratio*`, the
+  base executable's mean divided by the comparison executable's mean.
+* `controller compacts/iter*` shows the main Ractor's
+  `GC.stat(:compact_count)` delta. Every global compacting cycle increments
+  it, but it is not a sum of worker counters.
+
+The starred columns are controller-observed deltas, not additive with the
+worker-sum columns: a global or compacting cycle triggered by a sampled
+worker is already included in that worker's counts as a major GC. They can
+also reflect cycles from Ractors the harness does not sample.
+
+Worker records in the JSON output never contain the controller-observed
+counters, and controller counters are never summed across workers.
+
 ## Rendering a graph
 
 `--graph` option of `run_benchmarks.rb` allows you to render benchmark results as a graph.

harness-gc/harness.rb

@@ -1,4 +1,5 @@
 require_relative "../harness/harness-common"
+require_relative "../harness/gc-stats"
 
 WARMUP_ITRS = Integer(ENV.fetch('WARMUP_ITRS', 15))
 MIN_BENCH_ITRS = Integer(ENV.fetch('MIN_BENCH_ITRS', 10))
@@ -12,24 +13,6 @@ def realtime
   Process.clock_gettime(Process::CLOCK_MONOTONIC) - r0
 end
 
-def gc_stat_heap_snapshot
-  return {} unless GC.respond_to?(:stat_heap)
-  GC.stat_heap
-end
-
-def gc_stat_heap_delta(before, after)
-  delta = {}
-  after.each do |heap_idx, after_stats|
-    before_stats = before[heap_idx] || {}
-    heap_delta = {}
-    after_stats.each do |key, val|
-      next unless val.is_a?(Numeric) && before_stats.key?(key)
-      heap_delta[key] = val - before_stats[key]
-    end
-    delta[heap_idx] = heap_delta unless heap_delta.empty?
-  end
-  delta
-end
 
 def run_benchmark(_num_itrs_hint, **, &block)
   times = []
@@ -39,38 +22,43 @@ def run_benchmark(_num_itrs_hint, **, &block)
   gc_counts = []
   major_counts = []
   minor_counts = []
+  global_counts = []
   gc_heap_deltas = []
+  gc_total_time_ns = []
   total_time = 0
   num_itrs = 0
 
   has_marking = GC.stat.key?(:marking_time)
   has_sweeping = GC.stat.key?(:sweeping_time)
+  has_global_gc = GCStats.stat_available?(:global_gc_count)
 
   header = "itr:   time"
   header << "   marking" if has_marking
   header << "  sweeping" if has_sweeping
   header << "  gc_count"
   header << "     major"
   header << "     minor"
+  header << "   global*" if has_global_gc
   header << "  maj/min"
   puts header
+  puts "(* process/controller-observed; may overlap the other GC counts and is not additive.)" if has_global_gc
 
   begin
-    gc_before = GC.stat
-    heap_before = gc_stat_heap_snapshot
+    gc_before = GCStats.snapshot
+    global_gc_before = GC.stat(:global_gc_count) if has_global_gc
 
     time = realtime(&block)
     num_itrs += 1
 
-    gc_after = GC.stat
-    heap_after = gc_stat_heap_snapshot
+    sample = GCStats.delta(gc_before, GCStats.snapshot)
 
     time_ms = (1000 * time).to_i
-    mark_delta = has_marking ? gc_after[:marking_time] - gc_before[:marking_time] : 0
-    sweep_delta = has_sweeping ? gc_after[:sweeping_time] - gc_before[:sweeping_time] : 0
-    count_delta = gc_after[:count] - gc_before[:count]
-    major_delta = gc_after[:major_gc_count] - gc_before[:major_gc_count]
-    minor_delta = gc_after[:minor_gc_count] - gc_before[:minor_gc_count]
+    mark_delta = has_marking ? sample["gc_marking_time"] : 0
+    sweep_delta = has_sweeping ? sample["gc_sweeping_time"] : 0
+    count_delta = sample["gc_count"]
+    major_delta = sample["gc_major_count"]
+    minor_delta = sample["gc_minor_count"]
+    global_delta = has_global_gc ? GC.stat(:global_gc_count) - global_gc_before : nil
     ratio_str = minor_delta > 0 ? "%.2f" % (major_delta.to_f / minor_delta) : "-"
 
     itr_str = "%4s %6s" % ["##{num_itrs}:", "#{time_ms}ms"]
@@ -79,6 +67,7 @@ def run_benchmark(_num_itrs_hint, **, &block)
     itr_str << " %9d" % count_delta
     itr_str << " %9d" % major_delta
     itr_str << " %9d" % minor_delta
+    itr_str << " %9d" % global_delta if has_global_gc
     itr_str << "%9s" % ratio_str
     puts itr_str
 
@@ -89,7 +78,9 @@ def run_benchmark(_num_itrs_hint, **, &block)
     gc_counts << count_delta
     major_counts << major_delta
     minor_counts << minor_delta
-    gc_heap_deltas << gc_stat_heap_delta(heap_before, heap_after)
+    global_counts << global_delta if has_global_gc
+    gc_heap_deltas << sample["gc_stat_heap_delta"]
+    gc_total_time_ns << sample["gc_total_time_ns"]
     total_time += time
   end until num_itrs >= WARMUP_ITRS + MIN_BENCH_ITRS and total_time >= MIN_BENCH_TIME
 
@@ -109,7 +100,16 @@ def run_benchmark(_num_itrs_hint, **, &block)
   extra["gc_major_count_bench"] = major_counts[bench_range]
   extra["gc_minor_count_warmup"] = minor_counts[warmup_range]
   extra["gc_minor_count_bench"] = minor_counts[bench_range]
+  if has_global_gc
+    extra["gc_global_count_warmup"] = global_counts[warmup_range]
+    extra["gc_global_count_bench"] = global_counts[bench_range]
+  end
   extra["gc_stat_heap_deltas"] = gc_heap_deltas[bench_range]
+  if gc_total_time_ns.all?(Numeric)
+    gc_total_time_ms = gc_total_time_ns.map { |ns| ns / 1_000_000.0 }
+    extra["gc_total_time_warmup"] = gc_total_time_ms[warmup_range]
+    extra["gc_total_time_bench"] = gc_total_time_ms[bench_range]
+  end
 
   # Snapshot heap utilisation after benchmark
   if GC.respond_to?(:stat_heap)

harness-ractor/harness.rb

@@ -4,6 +4,20 @@
 Warning[:experimental] = false
 ENV["RUBY_BENCH_RACTOR_HARNESS"] = "1"
 
+RACTOR_GC_ENABLED = ENV["RUBY_BENCH_RACTOR_GC"] == "1"
+require_relative '../harness/gc-stats' if RACTOR_GC_ENABLED
+
+CONTROLLER_GC_SERIES = if RACTOR_GC_ENABLED
+  {
+    "gc_global_count_bench" => [:global_gc_count, "global*"],
+    "gc_controller_compact_count_bench" => [:compact_count, "compacts*"],
+  }.select { |_name, (stat_key, _label)| GCStats.stat_available?(stat_key) }
+    .transform_values(&:freeze)
+    .freeze
+else
+  {}.freeze
+end
+
 default_ractors = [
   0, # without ractor
   1, 2, 4, 6, 8#, 12, 16, 32
@@ -32,27 +46,41 @@ def join
 def run_benchmark(num_itrs_hint, ractor_args: [], &block)
   warmup_itrs = Integer(ENV.fetch('WARMUP_ITRS', 5))
   bench_itrs = Integer(ENV.fetch('MIN_BENCH_ITRS', num_itrs_hint))
-  if bench_itrs > MAX_ITERS
-    bench_itrs = MAX_ITERS
+  bench_itrs = MAX_ITERS if bench_itrs > MAX_ITERS
+
+  if RACTOR_GC_ENABLED
+    check_ractor_gc_support
+    gc_config = GC.config.transform_keys(&:to_s) if GC.respond_to?(:config)
+    GCStats.with_measure_total_time do
+      run_warmup(warmup_itrs, ractor_args, &block)
+      run_benchmark_gc(bench_itrs, Ractor.make_shareable(block), ractor_args, gc_config: gc_config)
+    end
+  else
+    puts "r:   itr:   time"
+    run_warmup(warmup_itrs, ractor_args, &block)
+    run_benchmark_timing(bench_itrs, ractor_args, &block)
   end
-  # { num_ractors => [itr_in_ms, ...] }
-  stats = Hash.new { |h,k| h[k] = [] }
+end
 
-  header = "r:   itr:   time"
-  puts header
+def check_ractor_gc_support
+  unless GCStats.ractor_local_gc_supported?
+    raise NotImplementedError, "Ractor GC metrics require Ruby 4.1 or newer"
+  end
+  unless GC.respond_to?(:total_time) && GC.respond_to?(:measure_total_time) && GC.respond_to?(:measure_total_time=)
+    raise NotImplementedError, "Ractor GC metrics require GC.total_time and GC.measure_total_time="
+  end
+end
 
-  i = 0
-  while i < warmup_itrs
-    args = if ractor_args.empty?
-      []
-    else
-      ractor_deep_dup(ractor_args)
-    end
-    block.call *([0] + args)
-    i += 1
+def run_warmup(warmup_itrs, ractor_args, &block)
+  warmup_itrs.times do
+    args = ractor_args.empty? ? [] : ractor_deep_dup(ractor_args)
+    block.call(*([0] + args))
   end
+end
+
+def run_benchmark_timing(bench_itrs, ractor_args, &block)
+  stats = Hash.new { |h,k| h[k] = [] }
 
-  blk = Ractor.make_shareable(block)
   RACTORS.each do |rs|
     num_itrs = 0
     while num_itrs < bench_itrs
@@ -80,6 +108,120 @@ def run_benchmark(num_itrs_hint, ractor_args: [], &block)
   return_results([], stats.values.flatten, bench_by_ractors: stats)
 end
 
+RACTOR_GC_SERIES = {
+  "gc_count_bench" => "gc_count",
+  "gc_major_count_bench" => "gc_major_count",
+  "gc_minor_count_bench" => "gc_minor_count",
+  "gc_marking_time_bench" => "gc_marking_time",
+  "gc_sweeping_time_bench" => "gc_sweeping_time",
+  "gc_total_time_bench" => "gc_total_time_ns",
+}.freeze
+
+def run_benchmark_gc(bench_itrs, block, ractor_args, gc_config:)
+  stats = Hash.new { |h,k| h[k] = [] }
+  gc_by_ractors = {}
+
+  header = +"r:   itr:   time   gc_total   marking  sweeping  gc_count     major     minor"
+  CONTROLLER_GC_SERIES.each_value { |(_stat_key, label)| header << " %9s" % label }
+  puts header
+  puts "(* process/controller-observed; may overlap the other GC counts and is not additive.)" if CONTROLLER_GC_SERIES.any?
+
+  RACTORS.each do |rs|
+    group = { "gc_worker_samples" => [] }
+    group["gc_controller_samples"] = [] if rs > 0
+    series = Hash.new { |h,k| h[k] = [] }
+
+    num_itrs = 0
+    while num_itrs < bench_itrs
+      num_itrs += 1
+      elapsed, worker_samples, controller_sample, controller_deltas = run_ractor_gc_iteration(rs, ractor_args, &block)
+      stats[rs] << elapsed
+      group["gc_worker_samples"] << worker_samples
+      group["gc_controller_samples"] << controller_sample if controller_sample
+
+      agg = GCStats.aggregate(worker_samples)
+      total_ms = agg["gc_total_time_ns"]&.fdiv(1_000_000)
+      RACTOR_GC_SERIES.each do |series_name, field|
+        series[series_name] << (field == "gc_total_time_ns" ? total_ms : agg[field])
+      end
+      CONTROLLER_GC_SERIES.each_key { |series_name| series[series_name] << controller_deltas[series_name] }
+
+      itr_str = "%-3s %4s %6s" % [rs, "##{num_itrs}:", "#{(1000 * elapsed).to_i}ms"]
+      itr_str << " %8s" % (total_ms ? "%.1fms" % total_ms : "N/A")
+      itr_str << " %8s" % (agg["gc_marking_time"] ? "#{agg["gc_marking_time"]}ms" : "N/A")
+      itr_str << " %8s" % (agg["gc_sweeping_time"] ? "#{agg["gc_sweeping_time"]}ms" : "N/A")
+      itr_str << " %9s %9s %9s" % [agg["gc_count"], agg["gc_major_count"], agg["gc_minor_count"]].map { |v| v.nil? ? "N/A" : v.to_s }
+      CONTROLLER_GC_SERIES.each_key { |series_name| itr_str << " %9s" % (controller_deltas[series_name] || "N/A") }
+      puts itr_str
+    end
+
+    series.each do |name, values|
+      group[name] = values
+    end
+    gc_by_ractors[rs] = group
+  end
+
+  extra = {
+    bench_by_ractors: stats,
+    gc_scope: "ractor-local-workload",
+    gc_stat_scope: "ractor-local",
+    gc_measure_total_time_scope: "ractor-local",
+    gc_by_ractors: gc_by_ractors,
+  }
+  extra[:gc_config] = gc_config if gc_config
+  return_results([], stats.values.flatten, **extra)
+end
+
+def controller_gc_snapshot
+  CONTROLLER_GC_SERIES.transform_values { |(stat_key, _label)| GC.stat(stat_key) }
+end
+
+def controller_gc_deltas(before, after)
+  before.each_with_object({}) do |(series_name, before_value), deltas|
+    after_value = after[series_name]
+    deltas[series_name] = after_value - before_value if before_value.is_a?(Numeric) && after_value.is_a?(Numeric)
+  end
+end
+
+def run_ractor_gc_iteration(num_ractors, ractor_args, &block)
+  return run_controller_gc_iteration(ractor_args, &block) if num_ractors.zero?
+
+  controller_before = GCStats.snapshot
+  counters_before = controller_gc_snapshot
+  started = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+
+  pending = []
+  num_ractors.times do |worker_index|
+    pending << Ractor.new(worker_index, block, num_ractors, *ractor_args) do |index, workload, count, *args|
+      sample = GCStats.measure(count, *args, &workload)
+      sample["worker_index"] = index
+      sample
+    end
+  end
+
+  samples = Array.new(num_ractors)
+  while pending.any?
+    ractor, worker_sample = Ractor.select(*pending)
+    pending.delete(ractor)
+    samples[worker_sample["worker_index"]] = worker_sample
+  end
+
+  elapsed = Process.clock_gettime(Process::CLOCK_MONOTONIC) - started
+  counters_after = controller_gc_snapshot
+  controller_sample = GCStats.delta(controller_before, GCStats.snapshot)
+  [elapsed, samples, controller_sample, controller_gc_deltas(counters_before, counters_after)]
+end
+
+def run_controller_gc_iteration(ractor_args, &block)
+  counters_before = controller_gc_snapshot
+  started = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+  sample = GCStats.measure(0, *ractor_deep_dup(ractor_args), &block)
+  elapsed = Process.clock_gettime(Process::CLOCK_MONOTONIC) - started
+  counters_after = controller_gc_snapshot
+  sample["worker_index"] = 0
+  [elapsed, [sample], nil, controller_gc_deltas(counters_before, counters_after)]
+end
+
 # NOTE: we use `ractor_deep_dup` instead of `Ractor.make_shareable(copy: true)` for the case of
 # sending args to the block without a ractor because the arguments passed to `run_benchmark` are
 # sometimes modified, and we want to allow that because it improves compatibility. We don't want