Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 32 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -300,6 +300,38 @@ 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 with per-Ractor global GC attribution
([ruby/ruby#19147](https://github.com/ruby/ruby/pull/19147)); 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. `GCs/iter` is the sum of `minor/iter`,
`major/iter`, and `global/iter`; a global cycle counts under `global` on
the Ractor that initiated it, not under `major`. Single-executable reports
also show `GC ms/worker`, which divides each iteration's worker-sum GC
time by its sampled worker count, then averages.
* `controller compacts/iter*` shows the main Ractor's
`GC.stat(:compact_count)` delta. Every global compacting cycle increments
it in every object space, so it is not summed across workers.

Worker records in the JSON output never contain the controller-observed
counter, and it is never summed across workers.

## Rendering a graph

`--graph` option of `run_benchmarks.rb` allows you to render benchmark results as a graph.
Expand Down
55 changes: 27 additions & 28 deletions harness-gc/harness.rb
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
require_relative "../harness/harness-common"
require_relative "../lib/gc_stats"

WARMUP_ITRS = Integer(ENV.fetch('WARMUP_ITRS', 15))
MIN_BENCH_ITRS = Integer(ENV.fetch('MIN_BENCH_ITRS', 10))
Expand All @@ -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 = []
Expand All @@ -39,38 +22,42 @@ 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

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"]
Expand All @@ -79,6 +66,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

Expand All @@ -89,7 +77,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

Expand All @@ -109,7 +99,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)
Expand Down
177 changes: 161 additions & 16 deletions harness-ractor/harness.rb
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,19 @@
Warning[:experimental] = false
ENV["RUBY_BENCH_RACTOR_HARNESS"] = "1"

RACTOR_GC_ENABLED = ENV["RUBY_BENCH_RACTOR_GC"] == "1"
require_relative '../lib/gc_stats' if RACTOR_GC_ENABLED

CONTROLLER_GC_SERIES = if RACTOR_GC_ENABLED
{
"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
Expand Down Expand Up @@ -32,27 +45,44 @@ 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
unless GCStats.global_gc_attributed?
raise NotImplementedError, "Ractor GC metrics require per-Ractor global GC attribution (ruby/ruby#19147)"
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
Expand Down Expand Up @@ -80,6 +110,121 @@ 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_global_count_bench" => "gc_global_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 global"
CONTROLLER_GC_SERIES.each_value { |(_stat_key, label)| header << " %9s" % label }
puts header
puts "(* controller-observed compacting cycles; may overlap global 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 %9s" % [agg["gc_count"], agg["gc_major_count"], agg["gc_minor_count"], agg["gc_global_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
Expand Down
4 changes: 4 additions & 0 deletions lib/argument_parser.rb
Original file line number Diff line number Diff line change
Expand Up @@ -111,6 +111,10 @@ def parse(argv)
ENV["WARMUP_ITRS"] = n
end

opts.on("--ractor-gc", "collect Ractor-local GC metrics when using the Ractor harness (the target must use Ruby 4.1 or newer with per-Ractor global GC attribution)") do
ENV["RUBY_BENCH_RACTOR_GC"] = "1"
end

opts.on("--bench=N", "the number of benchmark iterations for the default harness (default: 10). Also defaults MIN_BENCH_TIME to 0.") do |n|
ENV["MIN_BENCH_ITRS"] = n
ENV["MIN_BENCH_TIME"] ||= "0"
Expand Down
Loading
Loading