Skip to content

Commit 23e8d8f

Browse files
authored
fix(benchmark): harden target monitoring
Closes #3637 ## Summary - Add a benchmark target monitor that starts at the measured benchmark window and verifies the target before any Bencher payload files are written. - Preserve the pre-measurement target log to `bench_results/target_startup_before_benchmark.log`, then blank the live log so the existing workflow grep cannot match pre-benchmark `died UNEXPECTEDLY` lines. - Treat the node-renderer master's `died UNEXPECTEDLY` log line as an explicit Pro worker restart signal and fail before uploading partial metrics. ## Tests - `bundle exec rspec benchmarks/spec/benchmark_target_monitor_spec.rb` - `bundle exec rspec benchmarks/spec` - `bundle exec rubocop benchmarks/bench.rb benchmarks/bench-node-renderer.rb benchmarks/lib/benchmark_helpers.rb benchmarks/lib/benchmark_target_monitor.rb benchmarks/spec/benchmark_target_monitor_spec.rb` - `bundle exec rubocop` (baseline fails on unrelated `react_on_rails/spike/3313_prism_gemfile_rewriter/*` offenses; changed-file RuboCop and hooks are clean) - `/Users/justin/.agents/skills/autoreview/scripts/autoreview --mode local` - pre-commit and pre-push hooks reran changed-file RuboCop with no offenses ## Design Calls - Kept the implementation in benchmark scripts/tests and did not edit CI workflow YAML. - Used log windowing inside the benchmark scripts so #3579's existing post-run workflow grep now sees only measured-run log content. - Preserved successful-startup/pre-measure logs as an uploaded benchmark artifact; startup crashes that happen before benchmark scripts run still use the existing workflow log dump because improving that path further would require workflow YAML changes. Labels: benchmark, ci-tooling <!-- CURSOR_SUMMARY --> --- > [!NOTE] > **Low Risk** > Changes are confined to benchmark scripts and CI env vars already in use; they tighten when metrics are written without touching app runtime or auth. > > **Overview** > Benchmark runs now **gate Bencher uploads** on target health, not only on green Vegeta/k6 results. > > A new **`BenchmarkTargetMonitor`** starts at the measured window (from `TARGET_PID` / `TARGET_LOG`), copies pre-run logs to `target_startup_before_benchmark.log`, overwrites the live log with newlines so startup `died UNEXPECTEDLY` lines cannot pollute post-run checks, then **verifies** the target PID is still alive and that no unexpected Pro node-renderer worker restart was logged during the run. **`write_benchmark_payload`** runs that verification before writing BMF/display JSON; **`bench.rb`** and **`bench-node-renderer.rb`** call the monitor and exit with a GitHub Actions `::error::` if monitoring fails after an otherwise successful suite. > > Specs cover log windowing, PID validation, failure ordering (no payload write on monitor failure), and integration with the shared helper. > > <sup>Reviewed by [Cursor Bugbot](https://cursor.com/bugbot) for commit caf53a3. Bugbot is set up for automated code reviews on this repo. Configure [here](https://www.cursor.com/dashboard/bugbot).</sup> <!-- /CURSOR_SUMMARY --> <!-- This is an auto-generated comment: release notes by coderabbit.ai --> ## Summary by CodeRabbit * **New Features** * Benchmarks now run a pre/post measurement monitor that preserves startup logs, blanks live logs during measurement, verifies the target process and log integrity, and prevents writing results if the monitor detects failures (emits an error and exits). * **Tests** * Added comprehensive tests for log preservation, verification-before-write ordering, payload-write gating, and multiple failure scenarios. <!-- end of auto-generated comment: release notes by coderabbit.ai -->
1 parent 6710d47 commit 23e8d8f

5 files changed

Lines changed: 391 additions & 15 deletions

File tree

benchmarks/bench-node-renderer.rb

Lines changed: 12 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -351,6 +351,8 @@ def run_vegeta_suite(test_cases, bundle, label, bmf_collector, runner: method(:r
351351

352352
# Create output directory
353353
FileUtils.mkdir_p(OUTDIR)
354+
target_monitor = BenchmarkTargetMonitor.from_env(output_dir: OUTDIR)
355+
target_monitor.start_measurement!
354356

355357
# Initialize BMF collector for Bencher output
356358
bmf_collector = BmfCollector.new(prefix: BMF_PREFIX)
@@ -366,15 +368,17 @@ def run_vegeta_suite(test_cases, bundle, label, bmf_collector, runner: method(:r
366368
# Display summary
367369
display_summary(SUMMARY_TXT)
368370

369-
# Write the Bencher payload only on a fully green run. Guarding the write here
370-
# (rather than writing unconditionally before exit) makes the "never upload a
371-
# partial-success payload" invariant self-enforcing instead of relying on the
372-
# downstream Bencher step having no `if: always()`.
371+
# Write the Bencher payload only on a fully green run against a healthy target.
372+
# Guarding the write here makes the "never upload partial metrics" invariant
373+
# self-enforcing instead of relying on later workflow steps to discard data.
373374
if failed_tests.empty?
374-
# Append to existing Pro results.
375-
bmf_collector.write_bmf_json(BENCHMARK_JSON, append: true)
376-
# Display sidecar (summary table data) — append to match the BMF.
377-
bmf_collector.write_display_json(DISPLAY_JSON, append: true)
375+
begin
376+
# Append to existing Pro results and display sidecar rows.
377+
write_benchmark_payload(bmf_collector, target_monitor: target_monitor, append: true)
378+
rescue BenchmarkTargetMonitor::MonitorFailure => e
379+
$stdout.puts "::error::#{e.message}"
380+
exit 1
381+
end
378382
else
379383
$stdout.puts "::error::#{failed_tests.length} node renderer benchmark(s) failed: #{failed_tests.join(', ')}"
380384
exit 1

benchmarks/bench.rb

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -190,6 +190,8 @@ def run_benchmark_suite(routes, bmf_collector, runner: method(:benchmark_route))
190190
puts "Server is ready!"
191191

192192
FileUtils.mkdir_p(OUTDIR)
193+
target_monitor = BenchmarkTargetMonitor.from_env(output_dir: OUTDIR)
194+
target_monitor.start_measurement!
193195

194196
# Initialize BMF collector for Bencher output (suffix used for Core/Pro distinction)
195197
bmf_collector = BmfCollector.new(suffix: BMF_SUFFIX)
@@ -203,14 +205,16 @@ def run_benchmark_suite(routes, bmf_collector, runner: method(:benchmark_route))
203205
puts "\nSummary saved to #{SUMMARY_TXT}"
204206
system("column", "-t", "-s", "\t", SUMMARY_TXT)
205207

206-
# Write the Bencher payload only on a fully green run. Guarding the write here
207-
# (rather than writing unconditionally before exit) makes the "never upload a
208-
# partial-success payload" invariant self-enforcing instead of relying on the
209-
# downstream Bencher step having no `if: always()`.
208+
# Write the Bencher payload only on a fully green run against a healthy target.
209+
# Guarding the write here makes the "never upload partial metrics" invariant
210+
# self-enforcing instead of relying on later workflow steps to discard data.
210211
if failed_routes.empty?
211-
bmf_collector.write_bmf_json(BENCHMARK_JSON)
212-
# Display sidecar (summary table data) — written alongside the BMF.
213-
bmf_collector.write_display_json(DISPLAY_JSON)
212+
begin
213+
write_benchmark_payload(bmf_collector, target_monitor: target_monitor)
214+
rescue BenchmarkTargetMonitor::MonitorFailure => e
215+
$stdout.puts "::error::#{e.message}"
216+
exit 1
217+
end
214218
else
215219
$stdout.puts "::error::#{failed_routes.length} of #{routes.length} benchmark route(s) failed: " \
216220
"#{failed_routes.join(', ')}"

benchmarks/lib/benchmark_helpers.rb

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
require "fileutils"
55
require "net/http"
66
require "uri"
7+
require_relative "benchmark_target_monitor"
78

89
# Shared utilities for benchmark scripts
910
# Note: env_or_default and validation helpers are in benchmark_config.rb
@@ -100,3 +101,10 @@ def display_summary(summary_file)
100101
puts "\nSummary saved to #{summary_file}"
101102
system("column", "-t", "-s", "\t", summary_file)
102103
end
104+
105+
# Requires BENCHMARK_JSON and DISPLAY_JSON constants from benchmark_config.rb.
106+
def write_benchmark_payload(bmf_collector, target_monitor:, append: false)
107+
target_monitor.verify_after_measurement!
108+
bmf_collector.write_bmf_json(BENCHMARK_JSON, append: append)
109+
bmf_collector.write_display_json(DISPLAY_JSON, append: append)
110+
end
Lines changed: 140 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,140 @@
1+
# frozen_string_literal: true
2+
3+
require "fileutils"
4+
5+
# Guards benchmark payload writes against target process failures that happen
6+
# after the benchmark script starts measuring but before Bencher receives data.
7+
class BenchmarkTargetMonitor
8+
class MonitorFailure < StandardError; end
9+
10+
STARTUP_LOG_FILENAME = "target_startup_before_benchmark.log"
11+
UNEXPECTED_WORKER_RESTART = "died UNEXPECTEDLY"
12+
BLANK_CHUNK_SIZE = 8 * 1024 # balances allocation cost against write-call count
13+
BLANK_CHUNK = ("\n" * BLANK_CHUNK_SIZE).freeze
14+
15+
def self.from_env(output_dir:, env: ENV)
16+
new(
17+
target_pid: env["TARGET_PID"],
18+
target_log: env["TARGET_LOG"],
19+
output_dir: output_dir
20+
)
21+
end
22+
23+
def self.pid_alive?(pid)
24+
# Signal 0 checks process existence without delivering a signal. Zombies can
25+
# still answer as alive; CI parents reap quickly enough for this guard.
26+
Process.kill(0, pid)
27+
true
28+
rescue Errno::EPERM
29+
true
30+
rescue Errno::ESRCH
31+
false
32+
end
33+
34+
def initialize(target_pid: nil, target_log: nil, output_dir: nil, pid_alive: nil)
35+
@target_pid = present_string(target_pid)
36+
@target_log = present_string(target_log)
37+
@output_dir = output_dir
38+
@pid_alive = pid_alive || ->(pid) { self.class.pid_alive?(pid) }
39+
@measurement_started = false
40+
@log_windowed = false
41+
end
42+
43+
def start_measurement!
44+
return if @measurement_started
45+
46+
@measurement_started = true
47+
@log_windowed = target_log?
48+
if @target_log && !@log_windowed
49+
warn "BenchmarkTargetMonitor: TARGET_LOG=#{@target_log.inspect} set but log windowing disabled " \
50+
"(file does not exist or output_dir is nil); worker-restart checks will be skipped."
51+
end
52+
preserve_and_blank_target_log if @log_windowed
53+
end
54+
55+
def verify_after_measurement!
56+
unless @measurement_started
57+
raise MonitorFailure, "start_measurement! was never called; discarding benchmark metrics."
58+
end
59+
60+
verify_target_pid!
61+
verify_unexpected_worker_log!
62+
true
63+
end
64+
65+
private
66+
67+
def present_string(value)
68+
string_value = value.to_s
69+
string_value.empty? ? nil : string_value
70+
end
71+
72+
def target_log?
73+
@target_log && @output_dir && File.file?(@target_log)
74+
end
75+
76+
def preserve_and_blank_target_log
77+
FileUtils.mkdir_p(@output_dir)
78+
File.binwrite(File.join(@output_dir, STARTUP_LOG_FILENAME), File.binread(@target_log))
79+
blank_existing_log_bytes
80+
end
81+
82+
# Truncating a file that a running process already has open can leave sparse NUL
83+
# gaps when that process writes again at its old file offset. Overwriting the
84+
# startup bytes with newlines keeps the existing workflow grep text-only while
85+
# preventing pre-measurement events from matching the post-run scan.
86+
def blank_existing_log_bytes
87+
File.open(@target_log, "r+b") do |file|
88+
# Capture size after opening, so bytes appended before the open are blanked.
89+
# Bytes appended after this point belong to the measured window.
90+
remaining = file.size
91+
until remaining.zero?
92+
chunk_size = [remaining, BLANK_CHUNK_SIZE].min
93+
chunk = chunk_size == BLANK_CHUNK_SIZE ? BLANK_CHUNK : BLANK_CHUNK.byteslice(0, chunk_size)
94+
file.write(chunk)
95+
remaining -= chunk_size
96+
end
97+
end
98+
end
99+
100+
def verify_target_pid!
101+
return unless @target_pid
102+
103+
pid = Integer(@target_pid)
104+
unless pid.positive?
105+
raise MonitorFailure, "TARGET_PID=#{@target_pid.inspect} is not a positive integer; discarding " \
106+
"benchmark metrics because target liveness could not be verified."
107+
end
108+
109+
return if @pid_alive.call(pid)
110+
111+
raise MonitorFailure, "Benchmark target PID #{pid} exited during the measured benchmark window; " \
112+
"discarding benchmark metrics because the target process did not survive."
113+
rescue ArgumentError
114+
raise MonitorFailure, "TARGET_PID=#{@target_pid.inspect} is not an integer; discarding benchmark metrics " \
115+
"because target liveness could not be verified."
116+
end
117+
118+
def verify_unexpected_worker_log!
119+
return unless @log_windowed
120+
121+
matches = unexpected_worker_restart_lines
122+
return if matches.empty?
123+
124+
raise MonitorFailure, "Pro node-renderer worker restarted during the measured benchmark window. " \
125+
"The node-renderer master logged `#{UNEXPECTED_WORKER_RESTART}`, which means " \
126+
"a worker process died and was forked again; discarding benchmark metrics " \
127+
"instead of uploading partial data. Matching log line(s):\n#{matches.join("\n")}"
128+
end
129+
130+
def unexpected_worker_restart_lines
131+
File.readlines(@target_log, chomp: true).each_with_index.filter_map do |line, index|
132+
next unless line.include?(UNEXPECTED_WORKER_RESTART)
133+
134+
"#{index + 1}:#{line}"
135+
end
136+
rescue Errno::ENOENT
137+
raise MonitorFailure, "Target log #{@target_log.inspect} disappeared before post-measurement scan; " \
138+
"discarding benchmark metrics."
139+
end
140+
end

0 commit comments

Comments
 (0)