Introduce a GC harness.

Author: eightbitraptor

harness-gc/harness.rb

@@ -0,0 +1,112 @@
+require_relative "../harness/harness-common"
+
+WARMUP_ITRS = Integer(ENV.fetch('WARMUP_ITRS', 15))
+MIN_BENCH_ITRS = Integer(ENV.fetch('MIN_BENCH_ITRS', 10))
+MIN_BENCH_TIME = Integer(ENV.fetch('MIN_BENCH_TIME', 10))
+
+puts RUBY_DESCRIPTION
+
+def realtime
+  r0 = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+  yield
+  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 = []
+  marking_times = []
+  sweeping_times = []
+  gc_counts = []
+  gc_heap_deltas = []
+  total_time = 0
+  num_itrs = 0
+
+  has_marking = GC.stat.key?(:marking_time)
+  has_sweeping = GC.stat.key?(:sweeping_time)
+
+  header = "itr:   time"
+  header << "   marking" if has_marking
+  header << "  sweeping" if has_sweeping
+  header << "  gc_count"
+  puts header
+
+  begin
+    gc_before = GC.stat
+    heap_before = gc_stat_heap_snapshot
+
+    time = realtime(&block)
+    num_itrs += 1
+
+    gc_after = GC.stat
+    heap_after = gc_stat_heap_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]
+
+    itr_str = "%4s %6s" % ["##{num_itrs}:", "#{time_ms}ms"]
+    itr_str << " %9.1fms" % mark_delta if has_marking
+    itr_str << " %9.1fms" % sweep_delta if has_sweeping
+    itr_str << " %9d" % count_delta
+    puts itr_str
+
+    times << time
+    marking_times << mark_delta
+    sweeping_times << sweep_delta
+    gc_counts << count_delta
+    gc_heap_deltas << gc_stat_heap_delta(heap_before, heap_after)
+    total_time += time
+  end until num_itrs >= WARMUP_ITRS + MIN_BENCH_ITRS and total_time >= MIN_BENCH_TIME
+
+  warmup_range = 0...WARMUP_ITRS
+  bench_range = WARMUP_ITRS..-1
+
+  extra = {}
+  extra["gc_marking_time_warmup"] = marking_times[warmup_range]
+  extra["gc_marking_time_bench"] = marking_times[bench_range]
+  extra["gc_sweeping_time_warmup"] = sweeping_times[warmup_range]
+  extra["gc_sweeping_time_bench"] = sweeping_times[bench_range]
+  extra["gc_count_warmup"] = gc_counts[warmup_range]
+  extra["gc_count_bench"] = gc_counts[bench_range]
+  extra["gc_stat_heap_deltas"] = gc_heap_deltas[bench_range]
+
+  return_results(times[warmup_range], times[bench_range], **extra)
+
+  non_warmups = times[bench_range]
+  if non_warmups.size > 1
+    non_warmups_ms = ((non_warmups.sum / non_warmups.size) * 1000.0).to_i
+    puts "Average of last #{non_warmups.size}, non-warmup iters: #{non_warmups_ms}ms"
+
+    if has_marking
+      mark_bench = marking_times[bench_range]
+      avg_mark = mark_bench.sum / mark_bench.size
+      puts "Average marking time: %.1fms" % avg_mark
+    end
+
+    if has_sweeping
+      sweep_bench = sweeping_times[bench_range]
+      avg_sweep = sweep_bench.sum / sweep_bench.size
+      puts "Average sweeping time: %.1fms" % avg_sweep
+    end
+  end
+end

harness/harness-common.rb

@@ -135,11 +135,12 @@ def get_maxrss
 yb_env_var = ENV.fetch("RESULT_JSON_PATH", default_path)
 YB_OUTPUT_FILE = File.expand_path yb_env_var
 
-def return_results(warmup_iterations, bench_iterations)
+def return_results(warmup_iterations, bench_iterations, **extra)
   ruby_bench_results = {
     "RUBY_DESCRIPTION" => RUBY_DESCRIPTION,
     "warmup" => warmup_iterations,
     "bench" => bench_iterations,
+    **extra,
   }
 
   # Collect JIT stats before loading any additional code.

lib/benchmark_runner.rb

@@ -48,7 +48,7 @@ def write_csv(output_path, ruby_descriptions, table)
     end
 
     # Build output text string with metadata, table, and legend
-    def build_output_text(ruby_descriptions, table, format, bench_failures, include_rss: false)
+    def build_output_text(ruby_descriptions, table, format, bench_failures, include_rss: false, include_gc: false)
       base_name, *other_names = ruby_descriptions.keys
 
       output_str = +""
@@ -68,6 +68,10 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
           if include_rss
             output_str << "- RSS #{base_name}/#{name}: ratio of #{base_name}/#{name} RSS. Higher is better for #{name}. Above 1 means lower memory usage.\n"
           end
+          if include_gc
+            output_str << "- mark #{base_name}/#{name}: ratio of GC marking time. Higher is better for #{name}. Above 1 represents faster marking.\n"
+            output_str << "- sweep #{base_name}/#{name}: ratio of GC sweeping time. Higher is better for #{name}. Above 1 represents faster sweeping.\n"
+          end
         end
         output_str << "- ***: p < 0.001, **: p < 0.01, *: p < 0.05 (Welch's t-test)\n"
       end

lib/benchmark_runner/cli.rb

@@ -109,7 +109,7 @@ def run
       BenchmarkRunner.write_csv(output_path, ruby_descriptions, table)
 
       # Save the output in a text file that we can easily refer to
-      output_str = BenchmarkRunner.build_output_text(ruby_descriptions, table, format, bench_failures, include_rss: args.rss)
+      output_str = BenchmarkRunner.build_output_text(ruby_descriptions, table, format, bench_failures, include_rss: args.rss, include_gc: builder.include_gc?)
       out_txt_path = output_path + ".txt"
       File.open(out_txt_path, "w") { |f| f.write output_str }
 

lib/results_table_builder.rb

@@ -10,11 +10,16 @@ def initialize(executable_names:, bench_data:, include_rss: false, include_pvalu
     @bench_data = bench_data
     @include_rss = include_rss
     @include_pvalue = include_pvalue
+    @include_gc = detect_gc_data(bench_data)
     @base_name = executable_names.first
     @other_names = executable_names[1..]
     @bench_names = compute_bench_names
   end
 
+  def include_gc?
+    @include_gc
+  end
+
   def build
     table = [build_header]
     format = build_format
@@ -41,6 +46,10 @@ def build_header
     @executable_names.each do |name|
       header << "#{name} (ms)"
       header << "RSS (MiB)" if @include_rss
+      if @include_gc
+        header << "#{name} mark (ms)"
+        header << "#{name} sweep (ms)"
+      end
     end
 
     @other_names.each do |name|
@@ -60,6 +69,13 @@ def build_header
       end
     end
 
+    if @include_gc
+      @other_names.each do |name|
+        header << "mark #{@base_name}/#{name}"
+        header << "sweep #{@base_name}/#{name}"
+      end
+    end
+
     header
   end
 
@@ -69,6 +85,10 @@ def build_format
     @executable_names.each do |_name|
       format << "%s"
       format << "%.1f" if @include_rss
+      if @include_gc
+        format << "%s"
+        format << "%s"
+      end
     end
 
     @other_names.each do |_name|
@@ -88,6 +108,13 @@ def build_format
       end
     end
 
+    if @include_gc
+      @other_names.each do |_name|
+        format << "%s"
+        format << "%s"
+      end
+    end
+
     format
   end
 
@@ -100,28 +127,45 @@ def build_row(bench_name)
     base_t, *other_ts = times_no_warmup
     base_rss, *other_rsss = rsss
 
+    if @include_gc
+      marking_times = extract_gc_times(bench_name, 'gc_marking_time_bench')
+      sweeping_times = extract_gc_times(bench_name, 'gc_sweeping_time_bench')
+      base_mark, *other_marks = marking_times
+      base_sweep, *other_sweeps = sweeping_times
+    end
+
     row = [bench_name]
-    build_base_columns(row, base_t, base_rss)
-    build_comparison_columns(row, other_ts, other_rsss)
+    build_base_columns(row, base_t, base_rss, base_mark, base_sweep)
+    build_comparison_columns(row, other_ts, other_rsss, other_marks, other_sweeps)
     build_ratio_columns(row, base_t0, other_t0s, base_t, other_ts)
     build_rss_ratio_columns(row, base_rss, other_rsss)
+    build_gc_ratio_columns(row, base_mark, other_marks, base_sweep, other_sweeps)
 
     row
   end
 
-  def build_base_columns(row, base_t, base_rss)
+  def build_base_columns(row, base_t, base_rss, base_mark, base_sweep)
     row << format_time_with_stddev(base_t)
     row << base_rss if @include_rss
+    if @include_gc
+      row << format_time_with_stddev(base_mark)
+      row << format_time_with_stddev(base_sweep)
+    end
   end
 
-  def build_comparison_columns(row, other_ts, other_rsss)
-    other_ts.zip(other_rsss).each do |other_t, other_rss|
+  def build_comparison_columns(row, other_ts, other_rsss, other_marks, other_sweeps)
+    other_ts.each_with_index do |other_t, i|
       row << format_time_with_stddev(other_t)
-      row << other_rss if @include_rss
+      row << other_rsss[i] if @include_rss
+      if @include_gc
+        row << format_time_with_stddev(other_marks[i])
+        row << format_time_with_stddev(other_sweeps[i])
+      end
     end
   end
 
   def format_time_with_stddev(values)
+    return "N/A" if values.nil? || values.empty?
     "%.1f ± %.1f%%" % [mean(values), stddev_percent(values)]
   end
 
@@ -147,6 +191,26 @@ def build_rss_ratio_columns(row, base_rss, other_rsss)
     end
   end
 
+  def build_gc_ratio_columns(row, base_mark, other_marks, base_sweep, other_sweeps)
+    return unless @include_gc
+
+    (other_marks || []).each do |other_mark|
+      row << gc_ratio(base_mark, other_mark)
+    end
+    (other_sweeps || []).each do |other_sweep|
+      row << gc_ratio(base_sweep, other_sweep)
+    end
+  end
+
+  def gc_ratio(base, other)
+    if base.nil? || base.empty? || other.nil? || other.empty? ||
+        mean(other) == 0.0
+      return "N/A"
+    end
+    pval = Stats.welch_p_value(base, other)
+    format_ratio(mean(base) / mean(other), pval)
+  end
+
   def format_ratio(ratio, pval)
     sym = significance_symbol(pval)
     formatted = "%.3f" % ratio
@@ -211,6 +275,16 @@ def extract_rss_values(bench_name)
     end
   end
 
+  def extract_gc_times(bench_name, key)
+    @executable_names.map do |name|
+      bench_data_for(name, bench_name)[key] || []
+    end
+  end
+
+  def detect_gc_data(bench_data)
+    bench_data.values.any? { |benchmarks| benchmarks.values.any? { |d| d.is_a?(Hash) && d.key?('gc_marking_time_bench') } }
+  end
+
   def bench_data_for(name, bench_name)
     @bench_data[name][bench_name]
   end