Skip to content

Commit 0dbdc38

Browse files
Show GC results for every ruby when comparing builds
With three or more rubies, the GC time ratios and GC counts tables only had one row per comparison (base → other), so no ruby had its own row and the baseline appeared only on the left of each arrow. harness-gc also printed 0 live and free slots in the heap utilisation table on Ruby 3.4, because GC.stat_heap before 4.0 has no heap_live_slots or heap_free_slots. This commit adds a "GC per ruby" table that prints before the GC time ratios table. It has one row per ruby per benchmark, including the base, with the same absolute columns as the single-ruby GC summary. The table is left out when only one ruby runs, because the GC summary already shows those values. A benchmark is left out only when no ruby has GC activity. The legend and GC metric notes now say which table each sentence describes, and they describe each table's own skip rule. The Ractor GC ms/worker note now appears whenever a table shows that column. After the full GC, harness-gc now derives live and free slots from the per-heap total_allocated_objects and total_freed_objects counters when GC.stat_heap does not report them.
1 parent ab26700 commit 0dbdc38

6 files changed

Lines changed: 210 additions & 26 deletions

File tree

‎README.md‎

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -521,18 +521,21 @@ Ractor's own object space. The JSON output records the scope as
521521

522522
The text summary shows GC data in separate tables after the timing table.
523523
A single-executable report has one `GC summary` table. A comparison report
524-
has a `GC time ratios` table (base/comparison) and a `GC counts` table
525-
(base → comparison). A table hides a column that has no data in any row and
524+
has a `GC per ruby` table, a `GC time ratios` table (base/comparison), and a
525+
`GC counts` table (base → comparison). The `GC per ruby` table has one row
526+
for each ruby, including the base, with the absolute `GC summary` columns.
527+
A table hides a column that has no data in any row and
526528
lists the hidden columns below the table. A ratio column has no data when it
527529
is `N/A` in every row; a `0.000` ratio stays visible. Any other column has no
528530
data when it is zero or `N/A` in every row.
529531

530532
* Tables marked `worker sum` add the Ractor-local counters and GC times of
531533
the sampled workers of each iteration. `GCs/iter` is the sum of `minor/iter`,
532534
`major/iter`, and `global/iter`; a global cycle counts under `global` on
533-
the Ractor that initiated it, not under `major`. Single-executable reports
534-
also show `GC ms/worker`, which divides each iteration's worker-sum GC
535-
time by its sampled worker count, then averages.
535+
the Ractor that initiated it, not under `major`. The absolute GC tables
536+
(the single-executable `GC summary` and the `GC per ruby` table) also show
537+
`GC ms/worker`, which divides each iteration's worker-sum GC time by its
538+
sampled worker count, then averages.
536539
* `compacts*` shows the main Ractor's
537540
`GC.stat(:compact_count)` delta. Every global compacting cycle increments
538541
it in every object space, so it is not summed across workers.

‎harness/gc.rb‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -148,8 +148,9 @@ def run_benchmark(_num_itrs_hint, **, &block)
148148
heap_snapshot.each do |idx, stats|
149149
slot_size = stats[:slot_size] || 0
150150
eden_slots = stats[:heap_eden_slots] || 0
151-
live_slots = stats[:heap_live_slots] || 0
152-
free_slots = stats[:heap_free_slots] || 0
151+
# Ruby < 4.0 omits heap_live_slots/heap_free_slots; derive them from the per-heap counters.
152+
live_slots = stats[:heap_live_slots] || stats[:total_allocated_objects].to_i - stats[:total_freed_objects].to_i
153+
free_slots = stats[:heap_free_slots] || eden_slots - live_slots
153154
eden_pages = stats[:heap_eden_pages] || 0
154155
live_pct = eden_slots > 0 ? (live_slots * 100.0 / eden_slots) : 0.0
155156
mem_kib = page_size ? (eden_pages * page_size / 1024.0) : 0.0

‎lib/benchmark_runner.rb‎

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -74,6 +74,8 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
7474
sections ||= [{ table: table, format: format, failures: bench_failures, include_gc: include_gc, gc_tables: gc_tables, memory_tables: memory_tables }]
7575
has_gc_summary = sections.any? { |section| section[:include_gc] && section[:gc_tables] }
7676
has_memory_summary = sections.any? { |section| section[:memory_tables] }
77+
gc_table_list = sections.flat_map { |section| Array(section[:gc_tables]) }
78+
per_ruby_headers = gc_table_list.select { |gc_table| gc_table[:name] == 'GC per ruby' }.flat_map { |gc_table| gc_table[:rows].first }
7779
sections.each do |section|
7880
title = section[:title]
7981
output_str << "#{title}:\n" if title
@@ -93,10 +95,11 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
9395
end
9496
end
9597
if has_gc_summary
98+
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" unless per_ruby_headers.empty?
9699
output_str << "- GC time ratios are #{base_name}/comparison; above 1 means the comparison spent less GC time.\n"
97100
output_str << "- gc/iter, mark/iter, and sweep/iter compare total GC (or phase) time per benchmark iteration, so they include both per-GC cost and GC frequency changes.\n"
98101
output_str << "- gc/GC, mark/GC, and sweep/GC 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"
99-
output_str << "- GC counts show #{base_name} → comparison values, not ratios. Rows with no GC activity are omitted.\n"
102+
output_str << "- GC counts show #{base_name} → comparison values, not ratios. In GC time ratios and GC counts, a row is omitted when neither #{base_name} nor the comparison has GC activity.\n"
100103
end
101104
if has_memory_summary
102105
output_str << "- Scenario memory shows #{base_name} → comparison values, not ratios. Lower is better.\n"
@@ -105,10 +108,13 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
105108
output_str << "- ***: p < 0.001, **: p < 0.01, *: p < 0.05 (Welch's t-test)\n"
106109
end
107110
end
108-
gc_headers = sections.flat_map { |section| Array(section[:gc_tables]).flat_map { |gc_table| gc_table[:rows].first } }
111+
gc_headers = gc_table_list.flat_map { |gc_table| gc_table[:rows].first }
109112
if gc_headers.include?('compacts*')
110113
output_str << "GC metric notes:\n"
111-
output_str << "- compacts*: 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"
114+
compaction_note = +""
115+
compaction_note << " GC counts show #{base_name} → comparison values." unless other_names.empty?
116+
compaction_note << " GC per ruby shows the value for each ruby." if per_ruby_headers.include?('compacts*')
117+
output_str << "- compacts*: 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"
112118
end
113119

114120
ractor_gc_sections = sections.select { |section| section[:gc_scope] == 'ractor-local-workload' && section[:gc_tables] }
@@ -118,7 +124,7 @@ def build_output_text(ruby_descriptions, table, format, bench_failures, include_
118124
output_str << "Ractor GC scope note:\n"
119125
scope_columns = +"- Tables marked worker sum add Ractor-local counters and GC times across the sampled workers of each iteration"
120126
scope_columns << (worker_mode ? "; the main Ractor performs the count-0 workload of per-worker benchmarks." : ".")
121-
scope_columns << " GC ms/worker divides each iteration's worker-sum GC time by its sampled worker count, then averages." if other_names.empty?
127+
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')
122128
output_str << "#{scope_columns} Controller snapshots and per-worker heap detail are in the JSON output, not these tables.\n"
123129
output_str << "- Ruby's Ractor-retirement GC (after a worker's stack is torn down) is not sampled."
124130
output_str << " Ractors created by the workload of a per-worker benchmark are not sampled." if worker_mode

‎lib/results_table_builder.rb‎

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -124,7 +124,7 @@ def build_gc_tables
124124
return nil unless @include_gc
125125

126126
label_header = ["bench", *@row_layout.extra_header_columns]
127-
tables = @other_names.empty? ? [build_gc_absolute_table(label_header)] : build_gc_comparison_tables(label_header)
127+
tables = @other_names.empty? ? [build_gc_absolute_table(label_header)] : [build_gc_per_ruby_table(label_header), *build_gc_comparison_tables(label_header)]
128128
tables.compact!
129129
tables.empty? ? nil : tables
130130
end
@@ -192,6 +192,19 @@ def gc_count_columns
192192
columns
193193
end
194194

195+
def build_gc_per_ruby_table(label_header)
196+
rows = []
197+
gc_entries.each do |entry|
198+
data_by_name = @executable_names.to_h { |name| [name, bench_data_for(name, entry.data_key)] }
199+
next unless gc_activity?(*data_by_name.values.flat_map { |data| data.values_at(*GC_SERIES_KEYS) })
200+
201+
data_by_name.each do |name, data|
202+
rows << [gc_label_cells(entry) + [name], [data]] if GC_SERIES_KEYS.any? { |key| data.key?(key) }
203+
end
204+
end
205+
assemble_gc_table("GC per ruby", label_header + ["ruby"], rows, gc_absolute_columns)
206+
end
207+
195208
def build_gc_absolute_table(label_header)
196209
rows = gc_entries.filter_map do |entry|
197210
data = bench_data_for(@base_name, entry.data_key)

‎test/benchmark_runner_test.rb‎

Lines changed: 78 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -524,7 +524,8 @@ def git(dir, *args)
524524
assert_includes result, "- compacts*: the main Ractor's GC.stat(:compact_count) delta per iteration."
525525
assert_includes result, 'Every global compacting cycle increments compact_count in every object space.'
526526
assert_includes result, 'Do not sum it across workers.'
527-
assert_includes result, 'Comparison tables show ruby-base → comparison values.'
527+
assert_includes result, 'GC counts show ruby-base → comparison values.'
528+
refute_includes result, 'GC per ruby shows the value for each ruby.'
528529
refute_includes result, 'global GCs/iter'
529530
end
530531

@@ -546,7 +547,7 @@ def git(dir, *args)
546547
refute_includes result, 'Legend:'
547548
assert_includes result, "GC metric notes:\n"
548549
assert_includes result, "- compacts*: the main Ractor's GC.stat(:compact_count) delta per iteration."
549-
refute_includes result, 'Comparison tables show'
550+
refute_includes result, 'GC counts show'
550551
refute_includes result, 'global GCs/iter'
551552
end
552553

@@ -573,7 +574,7 @@ def git(dir, *args)
573574

574575
refute_includes result, 'GC metric notes:'
575576
assert_includes result, "the same run's GCs/iter count"
576-
assert_includes result, 'GC counts show ruby-base → comparison values, not ratios'
577+
assert_includes result, 'GC counts show ruby-base → comparison values, not ratios. In GC time ratios and GC counts, a row is omitted when neither ruby-base nor the comparison has GC activity.'
577578
end
578579

579580
it 'omits the Ractor scope note when the section rendered no GC table' do
@@ -597,6 +598,80 @@ def git(dir, *args)
597598
refute_includes result, 'Ractor GC scope note:'
598599
end
599600

601+
it 'prints the GC per ruby table before the GC ratio table, with its legend line' do
602+
ruby_descriptions = { 'master' => 'ruby 4.1.0dev', 'four' => 'ruby 4.0.6', 'three' => 'ruby 3.4.10' }
603+
sections = [
604+
{
605+
title: 'harness-gc',
606+
table: [['bench', 'master (ms)', 'four (ms)', 'three (ms)'], ['gcbench', '1.0', '2.0', '3.0']],
607+
format: ['%s', '%s', '%s', '%s'],
608+
failures: {},
609+
include_gc: true,
610+
gc_tables: [
611+
{ name: 'GC per ruby', scope: nil, hidden: [], rows: [
612+
['bench', 'ruby', 'GC ms/iter', 'compacts*'],
613+
['gcbench', 'master', '1.000', '0.0'],
614+
['gcbench', 'four', '2.000', '0.0'],
615+
['gcbench', 'three', '3.000', '0.0']
616+
] },
617+
{ name: 'GC time ratios', scope: nil, hidden: [], rows: [
618+
['bench', 'comparison', 'gc/iter'], ['gcbench', 'four', '0.500'], ['gcbench', 'three', '0.333']
619+
] },
620+
],
621+
},
622+
{
623+
title: 'harness',
624+
table: [['bench', 'master (ms)', 'four (ms)', 'three (ms)'], ['fib', '1.0', '2.0', '3.0']],
625+
format: ['%s', '%s', '%s', '%s'],
626+
failures: {},
627+
include_gc: false,
628+
}
629+
]
630+
631+
result = BenchmarkRunner.build_output_text(
632+
ruby_descriptions, sections.first[:table], sections.first[:format], {}, sections: sections
633+
)
634+
635+
per_ruby_at = result.index("GC per ruby (harness-gc):\n")
636+
summary_at = result.index("GC time ratios (harness-gc):\n")
637+
refute_nil per_ruby_at
638+
refute_nil summary_at
639+
assert_operator per_ruby_at, :<, summary_at
640+
assert_match(/^gcbench\s+master\s+1\.000\s+0\.0$/, result)
641+
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.'
642+
assert_includes result, 'Do not sum it across workers. GC counts show master → comparison values. GC per ruby shows the value for each ruby.'
643+
refute_includes result, 'GC per ruby (harness):'
644+
end
645+
646+
it 'explains GC ms/worker in the Ractor scope note when only the GC per ruby table shows it' do
647+
ruby_descriptions = { 'base' => 'ruby 4.1.0dev', 'exp' => 'ruby 4.1.0dev experiment' }
648+
sections = [
649+
{
650+
title: 'harness-ractor',
651+
table: [['bench', 'ractors', 'base (ms)', 'exp (ms)'], ['object-new', '2', '1.0', '2.0']],
652+
format: ['%s', '%s', '%s', '%s'],
653+
failures: {},
654+
include_gc: true,
655+
gc_tables: [
656+
{ name: 'GC per ruby', scope: 'worker sum', hidden: [], rows: [
657+
['bench', 'ractors', 'ruby', 'GC ms/iter', 'GC ms/worker'], ['object-new', '2', 'base', '4.000', '2.000']
658+
] },
659+
{ name: 'GC time ratios', scope: 'worker sum', hidden: [], rows: [
660+
['bench', 'ractors', 'gc/iter'], ['object-new', '2', '2.000']
661+
] },
662+
],
663+
gc_scope: 'ractor-local-workload',
664+
}
665+
]
666+
667+
result = BenchmarkRunner.build_output_text(
668+
ruby_descriptions, sections.first[:table], sections.first[:format], {}, sections: sections
669+
)
670+
671+
assert_includes result, "Ractor GC scope note:\n"
672+
assert_includes result, "GC ms/worker divides each iteration's worker-sum GC time by its sampled worker count, then averages."
673+
end
674+
600675
it 'includes RSS ratio legend when include_rss is true' do
601676
ruby_descriptions = {
602677
'ruby-base' => 'ruby 3.3.0',

0 commit comments

Comments
 (0)