From 424112c7a4ad5b3070c7a0da76ccd71060ed7aa7 Mon Sep 17 00:00:00 2001 From: Matt Valentine-House Date: Tue, 6 Oct 2026 12:38:38 +0100 Subject: [PATCH] Show GC results for every ruby when comparing builds MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit With three or more rubies, the GC summary 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. A new "GC per ruby" table now prints before the GC summary. It has one row per ruby per benchmark, with the same absolute columns as the single-ruby table. The table is left out when only one ruby runs, because the single-ruby report 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. 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. After the full GC, the harness now derives them from the per-heap total_allocated_objects and total_freed_objects counters. --- README.md | 7 +-- harness-gc/harness.rb | 5 +- lib/benchmark_runner.rb | 19 +++++-- lib/benchmark_runner/cli.rb | 3 ++ lib/results_table_builder.rb | 48 ++++++++++------- test/benchmark_runner_test.rb | 75 +++++++++++++++++++++++++-- test/results_table_builder_test.rb | 83 ++++++++++++++++++++++++++++++ 7 files changed, 210 insertions(+), 30 deletions(-) diff --git a/README.md b/README.md index db115f02..f761c00f 100644 --- a/README.md +++ b/README.md @@ -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. diff --git a/harness-gc/harness.rb b/harness-gc/harness.rb index ab627e1f..fec2e6b3 100644 --- a/harness-gc/harness.rb +++ b/harness-gc/harness.rb @@ -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 diff --git a/lib/benchmark_runner.rb b/lib/benchmark_runner.rb index 38f9222e..6fa0f67b 100644 --- a/lib/benchmark_runner.rb +++ b/lib/benchmark_runner.rb @@ -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" @@ -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" diff --git a/lib/benchmark_runner/cli.rb b/lib/benchmark_runner/cli.rb index ed59d2d1..1a59b0c2 100644 --- a/lib/benchmark_runner/cli.rb +++ b/lib/benchmark_runner/cli.rb @@ -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, @@ -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 diff --git a/lib/results_table_builder.rb b/lib/results_table_builder.rb index 8450331d..d8b52b3c 100644 --- a/lib/results_table_builder.rb +++ b/lib/results_table_builder.rb @@ -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) @@ -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)" : "" @@ -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') @@ -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 diff --git a/test/benchmark_runner_test.rb b/test/benchmark_runner_test.rb index 7792d8b5..886a0298 100644 --- a/test/benchmark_runner_test.rb +++ b/test/benchmark_runner_test.rb @@ -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 @@ -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 @@ -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 @@ -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', diff --git a/test/results_table_builder_test.rb b/test/results_table_builder_test.rb index 97246775..bddd5933 100644 --- a/test/results_table_builder_test.rb +++ b/test/results_table_builder_test.rb @@ -714,6 +714,66 @@ assert_equal ['%s'] * 9, gc_format assert_equal ['gcbench', '5.000', '2.000', '1.000', '11.0', '2.0', '8.0', '1.0', '0.0'], gc_table[1] end + + it 'gives every executable, including the baseline, its own row in the GC per ruby table' do + gc_data = ->(mark, major, minor) do + { + 'warmup' => [0.1], + 'bench' => [0.1, 0.1], + 'rss' => 10, + 'gc_marking_time_bench' => [mark, mark], + 'gc_sweeping_time_bench' => [1.0, 1.0], + 'gc_major_count_bench' => [major, major], + 'gc_minor_count_bench' => [minor, minor] + } + end + bench_data = { + 'master' => { 'gcbench' => gc_data.(4.0, 1, 9) }, + 'four' => { 'gcbench' => gc_data.(2.0, 0, 6) }, + 'three' => { 'gcbench' => gc_data.(3.0, 2, 4) } + } + + builder = ResultsTableBuilder.new( + executable_names: ['master', 'four', 'three'], + bench_data: bench_data + ) + + gc_table, gc_format = builder.build_gc_per_ruby + + assert_equal [ + 'bench', 'ruby', 'GC ms/iter', 'mark ms/iter', 'sweep ms/iter', 'GCs/iter', 'major/iter', 'minor/iter' + ], gc_table[0] + assert_equal ['%s'] * 8, gc_format + assert_equal [ + ['gcbench', 'master', 'N/A', '4.000', '1.000', '10.0', '1.0', '9.0'], + ['gcbench', 'four', 'N/A', '2.000', '1.000', '6.0', '0.0', '6.0'], + ['gcbench', 'three', 'N/A', '3.000', '1.000', '6.0', '2.0', '4.0'] + ], gc_table[1..] + end + + it 'omits the GC per ruby table for one executable or idle benchmarks, and keeps idle rubies when another is active' do + idle = { + 'warmup' => [0.1], + 'bench' => [0.1], + 'rss' => 10, + 'gc_marking_time_bench' => [0.0], + 'gc_sweeping_time_bench' => [0.0], + 'gc_major_count_bench' => [0], + 'gc_minor_count_bench' => [0] + } + + single = ResultsTableBuilder.new(executable_names: ['ruby'], bench_data: { 'ruby' => { 'fib' => idle.merge('gc_minor_count_bench' => [3]) } }) + assert_equal [nil, nil], single.build_gc_per_ruby + + multi = ResultsTableBuilder.new(executable_names: ['a', 'b'], bench_data: { 'a' => { 'fib' => idle }, 'b' => { 'fib' => idle } }) + assert_equal [nil, nil], multi.build_gc_per_ruby + + mixed = ResultsTableBuilder.new(executable_names: ['a', 'b'], bench_data: { 'a' => { 'fib' => idle }, 'b' => { 'fib' => idle.merge('gc_minor_count_bench' => [3]) } }) + assert_equal [ + ['fib', 'a', 'N/A', '0.000', '0.000', '0.0', '0.0', '0.0'], + ['fib', 'b', 'N/A', '0.000', '0.000', '3.0', '0.0', '3.0'] + ], mixed.build_gc_per_ruby[0][1..], 'an idle ruby keeps its row when another ruby has GC activity' + end end describe 'RSS sampling (rss_samples)' do @@ -1115,5 +1175,28 @@ def build_ractor_gc(bench_data) ], gc_table[0] assert_equal ['object-new', '0', '4.000', '4.000', 'N/A', 'N/A', '7.0', '1.0', '3.0', '3.0', '1.0'], gc_table[1] end + + it 'puts the ruby column after ractors in the GC per ruby table' do + bench_data = { + 'base' => { 'object-new' => ractor_gc_blob('2' => { bench: [1.0, 1.0], gc: gc_group(total: [12.0, 12.0], major: [2, 2], minor: [6, 6]) }) }, + 'candidate' => { 'object-new' => ractor_gc_blob('2' => { bench: [1.0, 1.0], gc: gc_group(total: [3.0, 3.0], major: [1, 1], minor: [3, 3]) }) } + } + expanded = RactorBreakdown.expand(bench_data) + builder = ResultsTableBuilder.new( + executable_names: bench_data.keys, + bench_data: expanded.bench_data, + row_layout: RactorRowLayout.new(groups: expanded.groups) + ) + + gc_table, gc_format = builder.build_gc_per_ruby + + assert_equal [ + 'bench', 'ractors', 'ruby', 'GC ms/iter (worker sum)', 'GC ms/worker', 'mark ms/iter (worker sum)', + 'sweep ms/iter (worker sum)', 'GCs/iter (worker sum)', 'major/iter (worker sum)', 'minor/iter (worker sum)' + ], gc_table[0] + assert_equal ['%s'] * 10, gc_format + assert_equal ['object-new', '2', 'base', '12.000', '12.000', 'N/A', 'N/A', '8.0', '2.0', '6.0'], gc_table[1] + assert_equal ['object-new', '2', 'candidate', '3.000', '3.000', 'N/A', 'N/A', '4.0', '1.0', '3.0'], gc_table[2] + end end end