Skip to content
Open
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
7 changes: 4 additions & 3 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -322,9 +322,10 @@ 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.
the Ractor that initiated it, not under `major`. The absolute GC tables
(single-executable reports and the `GC per ruby` table) 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.
Expand Down
5 changes: 3 additions & 2 deletions harness-gc/harness.rb
Original file line number Diff line number Diff line change
Expand Up @@ -148,8 +148,9 @@ def run_benchmark(_num_itrs_hint, **, &block)
heap_snapshot.each do |idx, stats|
slot_size = stats[:slot_size] || 0
eden_slots = stats[:heap_eden_slots] || 0
live_slots = stats[:heap_live_slots] || 0
free_slots = stats[:heap_free_slots] || 0
# Ruby < 4.0 omits heap_live_slots/heap_free_slots; derive them from the per-heap counters.
live_slots = stats[:heap_live_slots] || stats[:total_allocated_objects].to_i - stats[:total_freed_objects].to_i
free_slots = stats[:heap_free_slots] || eden_slots - live_slots
eden_pages = stats[:heap_eden_pages] || 0
live_pct = eden_slots > 0 ? (live_slots * 100.0 / eden_slots) : 0.0
mem_kib = page_size ? (eden_pages * page_size / 1024.0) : 0.0
Expand Down
19 changes: 15 additions & 4 deletions lib/benchmark_runner.rb
Original file line number Diff line number Diff line change
Expand Up @@ -65,6 +65,10 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
output_str << "#{title}:\n" if title
output_str << TableFormatter.new(section[:table], section[:format], section.fetch(:failures, {})).to_s + "\n"

if section[:include_gc] && section[:gc_per_ruby_table] && section[:gc_per_ruby_format]
output_str << (title ? "GC per ruby (#{title}):\n" : "GC per ruby:\n")
output_str << TableFormatter.new(section[:gc_per_ruby_table], section[:gc_per_ruby_format], {}).to_s + "\n"
end
if section[:include_gc] && section[:gc_table] && section[:gc_format]
output_str << (title ? "GC summary (#{title}):\n" : "GC summary:\n")
output_str << TableFormatter.new(section[:gc_table], section[:gc_format], {}).to_s + "\n"
Expand All @@ -81,25 +85,32 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
end
end
if has_gc_summary
if sections.any? { |section| section[:include_gc] && section[:gc_per_ruby_table] }
output_str << "- GC per ruby shows the mean GC values per benchmark iteration for each ruby. These values are not ratios. Benchmarks with no GC activity on any ruby are omitted.\n"
end
output_str << "- GC summary compares #{base_name} → comparison. Ratio columns are #{base_name}/comparison; above 1 means the comparison spent less GC time.\n"
output_str << "- gc/iter, mark/iter, and sweep/iter ratio compare total GC (or phase) time per benchmark iteration, so they include both per-GC cost and GC frequency changes.\n"
output_str << "- gc/GC, mark/GC, and sweep/GC ratio divide average GC (or phase) time by the same run's GCs/iter count; they are not complete per-cycle attribution of process-wide GC.\n"
output_str << "- GCs/iter, major/iter, minor/iter, controller compacts/iter*, and minor GC % show #{base_name} → comparison values, not ratios. Rows with no GC activity are omitted.\n"
output_str << "- In GC summary, GCs/iter, major/iter, minor/iter, controller compacts/iter*, and minor GC % show #{base_name} → comparison values, not ratios. A row is omitted when neither #{base_name} nor the comparison has GC activity.\n"
end
if include_pvalue
output_str << "- ***: p < 0.001, **: p < 0.01, *: p < 0.05 (Welch's t-test)\n"
end
end
gc_headers = sections.filter_map { |section| section[:gc_table]&.first }.flatten
gc_headers = sections.flat_map { |section| [section[:gc_table]&.first, section[:gc_per_ruby_table]&.first] }.compact.flatten
per_ruby_headers = sections.filter_map { |section| section[:gc_per_ruby_table]&.first }.flatten
if gc_headers.include?('controller compacts/iter*')
output_str << "GC metric notes:\n"
output_str << "- controller compacts/iter*: the main Ractor's GC.stat(:compact_count) delta per iteration. Every global compacting cycle increments compact_count in every object space. Do not sum it across workers.#{other_names.empty? ? '' : " Comparison tables show #{base_name} → comparison values."}\n"
compaction_note = +""
compaction_note << " GC summary shows #{base_name} → comparison values." unless other_names.empty?
compaction_note << " GC per ruby shows the value for each ruby." if per_ruby_headers.include?('controller compacts/iter*')
output_str << "- controller compacts/iter*: the main Ractor's GC.stat(:compact_count) delta per iteration. Every global compacting cycle increments compact_count in every object space. Do not sum it across workers.#{compaction_note}\n"
end

if sections.any? { |section| section[:gc_scope] == 'ractor-local-workload' && section[:gc_table] }
output_str << "Ractor GC scope note:\n"
scope_columns = +"- (worker sum) columns add Ractor-local counters across the sampled workers of each iteration; the main Ractor performs the count-0 workload."
scope_columns << " GC ms/worker divides each iteration's worker-sum GC time by its sampled worker count, then averages." if other_names.empty?
scope_columns << " GC ms/worker divides each iteration's worker-sum GC time by its sampled worker count, then averages." if gc_headers.include?('GC ms/worker')
output_str << "#{scope_columns} Controller snapshots and per-worker heap detail are in the JSON output, not this table.\n"
output_str << "- Ruby's Ractor-retirement GC (after a worker's stack is torn down) and Ractors created by the workload itself are not sampled.\n"
output_str << "- GC time is CPU-time accounting, not elapsed pause time; summed across Ractors it can exceed wall time.\n"
Expand Down
3 changes: 3 additions & 0 deletions lib/benchmark_runner/cli.rb
Original file line number Diff line number Diff line change
Expand Up @@ -194,6 +194,7 @@ def build_output_section(executable_names, bench_data, bench_failures, harness,
row_layout: layout
)
table, format, gc_table, gc_format = builder.build
gc_per_ruby_table, gc_per_ruby_format = builder.build_gc_per_ruby

section = {
title: harness,
Expand All @@ -203,6 +204,8 @@ def build_output_section(executable_names, bench_data, bench_failures, harness,
include_gc: builder.include_gc?,
gc_table: gc_table,
gc_format: gc_format,
gc_per_ruby_table: gc_per_ruby_table,
gc_per_ruby_format: gc_per_ruby_format,
}
section[:gc_scope] = 'ractor-local-workload' if ResultsTableBuilder.ractor_gc_data?(section_data)
section
Expand Down
48 changes: 30 additions & 18 deletions lib/results_table_builder.rb
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,13 @@ def build
[table, format, gc_table, build_gc_summary_format(gc_table)]
end

def build_gc_per_ruby
return [nil, nil] unless @include_gc && !@other_names.empty?

table = build_gc_absolute_table(["bench", *@row_layout.extra_header_columns], @executable_names)
[table, build_gc_summary_format(table)]
end

private

def has_complete_data?(bench_name)
Expand Down Expand Up @@ -128,7 +135,7 @@ def build_gc_summary_table
label_columns = ["bench", *@row_layout.extra_header_columns]

if @other_names.empty?
return build_gc_absolute_table(label_columns)
return build_gc_absolute_table(label_columns, [@base_name])
end

count_suffix = ractor_gc_table? ? " (worker sum)" : ""
Expand Down Expand Up @@ -168,11 +175,12 @@ def build_gc_summary_table
rows.size == 1 ? nil : rows
end

def build_gc_absolute_table(label_columns)
def build_gc_absolute_table(label_columns, names)
ractor = ractor_gc_table?
count_suffix = ractor ? " (worker sum)" : ""
per_ruby = names.size > 1

header = label_columns + ["GC ms/iter#{count_suffix}"]
header = label_columns + (per_ruby ? ["ruby"] : []) + ["GC ms/iter#{count_suffix}"]
header << "GC ms/worker" if ractor
header += ["mark ms/iter#{count_suffix}", "sweep ms/iter#{count_suffix}", "GCs/iter#{count_suffix}", "major/iter#{count_suffix}", "minor/iter#{count_suffix}"]
header << "global/iter#{count_suffix}" if gc_series_present?('gc_global_count_bench')
Expand All @@ -181,21 +189,25 @@ def build_gc_absolute_table(label_columns)
rows = [header]

gc_entries.each do |entry|
data = bench_data_for(@base_name, entry.data_key)
next unless GC_SERIES_KEYS.any? { |key| data.key?(key) }

cells = [format_gc_series_mean_precise(data['gc_total_time_bench'])]
cells << gc_ms_per_worker_cell(data['gc_total_time_bench'], data['gc_worker_samples']) if ractor
cells += [
format_gc_series_mean_precise(data['gc_marking_time_bench']),
format_gc_series_mean_precise(data['gc_sweeping_time_bench']),
format_gc_series_mean(gc_count_series(data)),
format_gc_series_mean(data['gc_major_count_bench']),
format_gc_series_mean(data['gc_minor_count_bench']),
]
cells << format_gc_series_mean(data['gc_global_count_bench']) if gc_series_present?('gc_global_count_bench')
cells << format_gc_series_mean(data['gc_controller_compact_count_bench']) if gc_series_present?('gc_controller_compact_count_bench')
rows << gc_label_cells(entry) + cells
data_by_name = names.to_h { |name| [name, bench_data_for(name, entry.data_key)] }
next if per_ruby && !gc_activity?(*data_by_name.values.flat_map { |data| data.values_at(*GC_SERIES_KEYS) })

data_by_name.each do |name, data|
next unless GC_SERIES_KEYS.any? { |key| data.key?(key) }

cells = [format_gc_series_mean_precise(data['gc_total_time_bench'])]
cells << gc_ms_per_worker_cell(data['gc_total_time_bench'], data['gc_worker_samples']) if ractor
cells += [
format_gc_series_mean_precise(data['gc_marking_time_bench']),
format_gc_series_mean_precise(data['gc_sweeping_time_bench']),
format_gc_series_mean(gc_count_series(data)),
format_gc_series_mean(data['gc_major_count_bench']),
format_gc_series_mean(data['gc_minor_count_bench']),
]
cells << format_gc_series_mean(data['gc_global_count_bench']) if gc_series_present?('gc_global_count_bench')
cells << format_gc_series_mean(data['gc_controller_compact_count_bench']) if gc_series_present?('gc_controller_compact_count_bench')
rows << gc_label_cells(entry) + (per_ruby ? [name] : []) + cells
end
end

rows.size == 1 ? nil : rows
Expand Down
75 changes: 72 additions & 3 deletions test/benchmark_runner_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -461,7 +461,8 @@
assert_includes result, "- controller compacts/iter*: the main Ractor's GC.stat(:compact_count) delta per iteration."
assert_includes result, 'Every global compacting cycle increments compact_count in every object space.'
assert_includes result, 'Do not sum it across workers.'
assert_includes result, 'Comparison tables show ruby-base → comparison values.'
assert_includes result, 'GC summary shows ruby-base → comparison values.'
refute_includes result, 'GC per ruby shows the value for each ruby.'
refute_includes result, 'global GCs/iter'
end

Expand All @@ -482,7 +483,7 @@
refute_includes result, 'Legend:'
assert_includes result, "GC metric notes:\n"
assert_includes result, "- controller compacts/iter*: the main Ractor's GC.stat(:compact_count) delta per iteration."
refute_includes result, 'Comparison tables show'
refute_includes result, 'GC summary shows'
refute_includes result, 'global GCs/iter'
end

Expand All @@ -508,7 +509,7 @@

refute_includes result, 'GC metric notes:'
assert_includes result, "the same run's GCs/iter count"
assert_includes result, 'show ruby-base → comparison values, not ratios'
assert_includes result, 'In GC summary, GCs/iter, major/iter, minor/iter, controller compacts/iter*, and minor GC % show ruby-base → comparison values, not ratios. A row is omitted when neither ruby-base nor the comparison has GC activity.'
end

it 'omits the Ractor scope note when the section rendered no GC table' do
Expand All @@ -532,6 +533,74 @@
refute_includes result, 'Ractor GC scope note:'
end

it 'prints the GC per ruby table before the GC summary, with its legend line' do
ruby_descriptions = { 'master' => 'ruby 4.1.0dev', 'four' => 'ruby 4.0.6', 'three' => 'ruby 3.4.10' }
sections = [
{
title: 'harness-gc',
table: [['bench', 'master (ms)', 'four (ms)', 'three (ms)'], ['gcbench', '1.0', '2.0', '3.0']],
format: ['%s', '%s', '%s', '%s'],
failures: {},
include_gc: true,
gc_per_ruby_table: [
['bench', 'ruby', 'GC ms/iter', 'controller compacts/iter*'],
['gcbench', 'master', '1.000', '0.0'],
['gcbench', 'four', '2.000', '0.0'],
['gcbench', 'three', '3.000', '0.0']
],
gc_per_ruby_format: ['%s', '%s', '%s', '%s'],
gc_table: [['bench', 'comparison', 'gc/iter ratio'], ['gcbench', 'four', '0.500'], ['gcbench', 'three', '0.333']],
gc_format: ['%s', '%s', '%s'],
},
{
title: 'harness',
table: [['bench', 'master (ms)', 'four (ms)', 'three (ms)'], ['fib', '1.0', '2.0', '3.0']],
format: ['%s', '%s', '%s', '%s'],
failures: {},
include_gc: false,
}
]

result = BenchmarkRunner.build_output_text(
ruby_descriptions, sections.first[:table], sections.first[:format], {}, sections: sections
)

per_ruby_at = result.index("GC per ruby (harness-gc):\n")
summary_at = result.index("GC summary (harness-gc):\n")
refute_nil per_ruby_at
refute_nil summary_at
assert_operator per_ruby_at, :<, summary_at
assert_match(/^gcbench\s+master\s+1\.000\s+0\.0$/, result)
assert_includes result, '- GC per ruby shows the mean GC values per benchmark iteration for each ruby. These values are not ratios. Benchmarks with no GC activity on any ruby are omitted.'
assert_includes result, 'Do not sum it across workers. GC summary shows master → comparison values. GC per ruby shows the value for each ruby.'
refute_includes result, 'GC per ruby (harness):'
end

it 'explains GC ms/worker in the Ractor scope note when only the GC per ruby table shows it' do
ruby_descriptions = { 'base' => 'ruby 4.1.0dev', 'exp' => 'ruby 4.1.0dev experiment' }
sections = [
{
title: 'harness-ractor',
table: [['bench', 'ractors', 'base (ms)', 'exp (ms)'], ['object-new', '2', '1.0', '2.0']],
format: ['%s', '%s', '%s', '%s'],
failures: {},
include_gc: true,
gc_per_ruby_table: [['bench', 'ractors', 'ruby', 'GC ms/iter (worker sum)', 'GC ms/worker'], ['object-new', '2', 'base', '4.000', '2.000']],
gc_per_ruby_format: ['%s'] * 5,
gc_table: [['bench', 'ractors', 'gc/iter ratio'], ['object-new', '2', '2.000']],
gc_format: ['%s'] * 3,
gc_scope: 'ractor-local-workload',
}
]

result = BenchmarkRunner.build_output_text(
ruby_descriptions, sections.first[:table], sections.first[:format], {}, sections: sections
)

assert_includes result, "Ractor GC scope note:\n"
assert_includes result, "GC ms/worker divides each iteration's worker-sum GC time by its sampled worker count, then averages."
end

it 'includes RSS ratio legend when include_rss is true' do
ruby_descriptions = {
'ruby-base' => 'ruby 3.3.0',
Expand Down
Loading
Loading