From fef4862b176de8ca3abf7be48679d8b88d088aa6 Mon Sep 17 00:00:00 2001 From: qti3e Date: Fri, 11 Apr 2025 21:54:34 -0400 Subject: [PATCH 1/4] add until option --- src/benchmark/executor.rs | 3 +- src/cli.rs | 12 +++- src/options.rs | 15 +++++ src/timer/mod.rs | 114 +++++++++++++++++++++++++++++++++++++- 4 files changed, 141 insertions(+), 3 deletions(-) diff --git a/src/benchmark/executor.rs b/src/benchmark/executor.rs index 915b735b6..80bd09c7d 100644 --- a/src/benchmark/executor.rs +++ b/src/benchmark/executor.rs @@ -65,6 +65,7 @@ fn run_command_and_measure_common( ) -> Result { let stdin = command_input_policy.get_stdin()?; let (stdout, stderr) = command_output_policy.get_stdout_stderr()?; + let until_text = command_output_policy.get_until_text(); command.stdin(stdin).stdout(stdout).stderr(stderr); command.env( @@ -76,7 +77,7 @@ fn run_command_and_measure_common( command.env("HYPERFINE_ITERATION", value); } - let result = execute_and_measure(command) + let result = execute_and_measure(command, until_text) .with_context(|| format!("Failed to run command '{command_name}'"))?; if !result.status.success() { diff --git a/src/cli.rs b/src/cli.rs index b12f6d34c..1986ef6dc 100644 --- a/src/cli.rs +++ b/src/cli.rs @@ -340,7 +340,7 @@ fn build_command() -> Command { .arg( Arg::new("output") .long("output") - .conflicts_with("show-output") + .conflicts_with_all(["show-output", "until"]) .action(ArgAction::Append) .value_name("WHERE") .help( @@ -364,6 +364,16 @@ fn build_command() -> Command { hyperfine 'my-command > output-${HYPERFINE_ITERATION}.log'\n\n", ), ) + .arg( + Arg::new("until") + .long("until") + .action(ArgAction::Set) + .conflicts_with_all(["show-output", "output"]) + .help( + "Run the command until it prints the given output in stdout" + ), + + ) .arg( Arg::new("input") .long("input") diff --git a/src/options.rs b/src/options.rs index 7c83da1c5..4346ad4d3 100644 --- a/src/options.rs +++ b/src/options.rs @@ -159,6 +159,9 @@ pub enum CommandOutputPolicy { /// Show command output on the terminal Inherit, + + /// Read until the given text is matched and then exit. + Until(Vec), } impl CommandOutputPolicy { @@ -175,10 +178,20 @@ impl CommandOutputPolicy { } CommandOutputPolicy::Inherit => (Stdio::inherit(), Stdio::inherit()), + + CommandOutputPolicy::Until(_) => (Stdio::piped(), Stdio::null()), }; Ok(streams) } + + pub fn get_until_text(&self) -> Option<&[u8]> { + if let CommandOutputPolicy::Until(v) = self { + Some(v.as_slice()) + } else { + None + } + } } #[derive(Debug, PartialEq)] @@ -351,6 +364,8 @@ impl Options { policies.push(policy); } policies + } else if let Some(text) = matches.get_one::("until") { + vec![CommandOutputPolicy::Until(text.as_bytes().to_vec())] } else { vec![CommandOutputPolicy::Null] }; diff --git a/src/timer/mod.rs b/src/timer/mod.rs index b2cd2654c..cc8d1734e 100644 --- a/src/timer/mod.rs +++ b/src/timer/mod.rs @@ -12,6 +12,7 @@ use nix::fcntl::{splice, SpliceFFlags}; use std::fs::File; #[cfg(target_os = "linux")] use std::os::fd::AsFd; +use std::os::unix::process::ExitStatusExt; #[cfg(target_os = "windows")] use windows_sys::Win32::System::Threading::CREATE_SUSPENDED; @@ -79,8 +80,91 @@ fn discard(output: ChildStdout) { } } +fn discard_until(output: ChildStdout, ptn: &[u8]) -> Result { + const CHUNK_SIZE: usize = 64 << 10; + + let mut output = output; + let mut buf = [0; CHUNK_SIZE]; + + let ptn_len = ptn.len(); + let lps = compute_lps_array(ptn); + let mut j = 0; // position of the character in ptn + let mut read_more = false; + + loop { + let n = output.read(&mut buf)?; + + if n == 0 { + return Ok(false); + } + + let mut i = 0; // position of the character in buf + if read_more && ptn[j] != buf[i] { + if j != 0 { + j = lps[j - 1]; + } else { + i += 1; + } + } + read_more = false; + + while i < n { + if ptn[j] == buf[i] { + i += 1; + j += 1; + } + + if j == ptn_len { + return Ok(true); + } + + if i == n { + read_more = true; + break; + } + + if ptn[j] == buf[i] { + continue; + } + + if j != 0 { + j = lps[j - 1]; + } else { + i += 1; + } + } + } +} + +#[inline(always)] +fn compute_lps_array(pattern: &[u8]) -> Vec { + let ptn_len = pattern.len(); + let mut lps = vec![0; ptn_len]; + + // length of the previous longest prefix suffix + let mut len = 0; + lps[0] = 0; + + // the loop calculates lps[i] for i = 1 to ptn_len-1 + let mut i = 1; + while i < ptn_len { + if pattern[i] == pattern[len] { + len += 1; + lps[i] = len; + i += 1; + } else if len != 0 { + len = lps[len - 1]; + } else { + lps[i] = 0; + i += 1; + } + } + + lps +} + /// Execute the given command and return a timing summary -pub fn execute_and_measure(mut command: Command) -> Result { +pub fn execute_and_measure(mut command: Command, until: Option<&[u8]>) -> Result { #[cfg(not(windows))] let cpu_timer = self::unix_timer::CPUTimer::start(); @@ -101,6 +185,34 @@ pub fn execute_and_measure(mut command: Command) -> Result { unsafe { self::windows_timer::CPUTimer::start_suspended_process(&child) } }; + if let Some(ptn) = until { + // Handle CommandOutputPolicy::Until + let output = child + .stdout + .take() + .expect("Expected a pipe when until text is present."); + + let status = if discard_until(output, ptn)? { + ExitStatus::from_raw(0) + } else { + ExitStatus::from_raw(-1) + }; + + let time_real = wallclock_timer.stop(); + let (time_user, time_system, memory_usage_byte) = cpu_timer.stop(); + + child.kill()?; + child.wait()?; + + return Ok(TimerResult { + time_real, + time_user, + time_system, + memory_usage_byte, + status, + }); + } + if let Some(output) = child.stdout.take() { // Handle CommandOutputPolicy::Pipe discard(output); From 02b8094fa43ef39a70926871489e1d6a3eaacb3b Mon Sep 17 00:00:00 2001 From: qti3e Date: Fri, 11 Apr 2025 22:23:18 -0400 Subject: [PATCH 2/4] send SIGTERM on unix not SIGKILL --- Cargo.toml | 2 +- src/timer/mod.rs | 14 +++++++++++++- 2 files changed, 14 insertions(+), 2 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index b3ef3dee6..7b53c22b7 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -45,7 +45,7 @@ windows-sys = { version = "0.59", features = [ once_cell = "1.19" [target.'cfg(target_os="linux")'.dependencies] -nix = { version = "0.29", features = ["zerocopy"] } +nix = { version = "0.29", features = ["zerocopy", "signal"] } [dependencies.clap] version = "4" diff --git a/src/timer/mod.rs b/src/timer/mod.rs index cc8d1734e..cb9b078b2 100644 --- a/src/timer/mod.rs +++ b/src/timer/mod.rs @@ -201,7 +201,19 @@ pub fn execute_and_measure(mut command: Command, until: Option<&[u8]>) -> Result let time_real = wallclock_timer.stop(); let (time_user, time_system, memory_usage_byte) = cpu_timer.stop(); - child.kill()?; + #[cfg(unix)] + { + // child.kill() sends SIGKILL we don't really want that. + use nix::sys::signal::{self, Signal}; + use nix::unistd::Pid; + signal::kill(Pid::from_raw(child.id() as i32), Signal::SIGTERM)?; + } + + #[cfg(not(unix))] + { + child.kill()?; + } + child.wait()?; return Ok(TimerResult { From ecd91776a7003afe8d8bd5005f6a5825478722d8 Mon Sep 17 00:00:00 2001 From: qti3e Date: Tue, 29 Apr 2025 16:10:52 -0400 Subject: [PATCH 3/4] only use --until on non-benchmark runs --- src/benchmark/executor.rs | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/src/benchmark/executor.rs b/src/benchmark/executor.rs index 80bd09c7d..63ab4e2e2 100644 --- a/src/benchmark/executor.rs +++ b/src/benchmark/executor.rs @@ -30,6 +30,14 @@ impl BenchmarkIteration { BenchmarkIteration::Benchmark(i) => Some(format!("{}", i)), } } + + /// Returns `true` if the benchmark iteration is [`NonBenchmarkRun`]. + /// + /// [`NonBenchmarkRun`]: BenchmarkIteration::NonBenchmarkRun + #[must_use] + pub fn is_non_benchmark_run(&self) -> bool { + matches!(self, Self::NonBenchmarkRun) + } } pub trait Executor { @@ -65,7 +73,12 @@ fn run_command_and_measure_common( ) -> Result { let stdin = command_input_policy.get_stdin()?; let (stdout, stderr) = command_output_policy.get_stdout_stderr()?; - let until_text = command_output_policy.get_until_text(); + let until_text = if iteration.is_non_benchmark_run() { + None + } else { + command_output_policy.get_until_text() + }; + command.stdin(stdin).stdout(stdout).stderr(stderr); command.env( From c239d6013c77085e8c01f40a97c82692d4157c3f Mon Sep 17 00:00:00 2001 From: qti3e Date: Fri, 5 Jun 2026 14:43:03 -0700 Subject: [PATCH 4/4] personal need changes Co-Authored-By: Claude Opus 4.5 --- README.md | 28 +++ src/benchmark/benchmark_result.rs | 10 +- src/benchmark/executor.rs | 79 +++++++- src/benchmark/mod.rs | 70 ++++++- src/benchmark/relative_speed.rs | 2 + src/benchmark/timing_result.rs | 5 +- src/cli.rs | 29 +++ src/command.rs | 107 +++++++++-- src/error.rs | 11 ++ src/export/csv.rs | 34 +++- src/export/markup.rs | 96 +++++++--- src/export/tests.rs | 64 +++++++ src/options.rs | 73 +++++++ src/output/format.rs | 77 ++++++++ src/output/warnings.rs | 44 +++++ src/timer/mod.rs | 309 ++++++++++++++++++++++++------ src/timer/unix_timer.rs | 2 +- 17 files changed, 933 insertions(+), 107 deletions(-) diff --git a/README.md b/README.md index ff6020064..67ca42f4b 100644 --- a/README.md +++ b/README.md @@ -5,6 +5,34 @@ A command-line benchmarking tool. +## Personal Fork Changes + +This fork includes the following modifications for more accurate low-level benchmarking: + +### CPU Pinning (`--cpu`) +Pin the benchmarked command to a specific CPU core using `sched_setaffinity`. This reduces noise from CPU migration during benchmarks. +```sh +hyperfine --cpu 0 --shell=none './my_program' +``` + +### Scheduling Priority (`--priority`) +Set the scheduling policy of the benchmarked command to `realtime` (SCHED_FIFO) or `idle` (SCHED_IDLE) for reduced scheduler interference. +```sh +hyperfine --priority realtime --shell=none './my_program' +``` +Note: Realtime priority requires `CAP_SYS_NICE` capability or root. Grant it with: +```sh +sudo setcap cap_sys_nice+ep $(which hyperfine) +``` + +### Post-Fork Timing (Linux) +Timing now starts after `fork()` but before `exec()`, excluding fork overhead from measurements. This provides more accurate timing for fast-starting programs. + +### Per-Child Memory Measurement (Linux) +Uses `wait4()` syscall to get per-child `rusage` instead of cumulative `getrusage(RUSAGE_CHILDREN)`, fixing memory reporting accuracy when running multiple benchmarks. + +--- + **Demo**: Benchmarking [`fd`](https://github.com/sharkdp/fd) and [`find`](https://www.gnu.org/software/findutils/): diff --git a/src/benchmark/benchmark_result.rs b/src/benchmark/benchmark_result.rs index 287c73bef..c77f11a34 100644 --- a/src/benchmark/benchmark_result.rs +++ b/src/benchmark/benchmark_result.rs @@ -42,10 +42,18 @@ pub struct BenchmarkResult { #[serde(skip_serializing_if = "Option::is_none")] pub times: Option>, - /// Maximum memory usage of the process, in bytes + /// Memory usage measurements of the process, in bytes (one per run) #[serde(skip_serializing_if = "Option::is_none")] pub memory_usage_byte: Option>, + /// Minimum memory usage across all runs, in bytes + #[serde(skip_serializing_if = "Option::is_none")] + pub memory_min: Option, + + /// Peak memory usage (max across all runs), in bytes + #[serde(skip_serializing_if = "Option::is_none")] + pub memory_max: Option, + /// Exit codes of all command invocations pub exit_codes: Vec>, diff --git a/src/benchmark/executor.rs b/src/benchmark/executor.rs index 63ab4e2e2..051b9f513 100644 --- a/src/benchmark/executor.rs +++ b/src/benchmark/executor.rs @@ -2,9 +2,13 @@ use std::os::windows::process::CommandExt; use std::process::ExitStatus; +#[cfg(target_os = "linux")] +use std::os::unix::process::CommandExt; + use crate::command::Command; use crate::options::{ - CmdFailureAction, CommandInputPolicy, CommandOutputPolicy, Options, OutputStyleOption, Shell, + CmdFailureAction, CommandInputPolicy, CommandOutputPolicy, Options, OutputStyleOption, + SchedulingPolicy, Shell, }; use crate::output::progress_bar::get_progress_bar; use crate::timer::{execute_and_measure, TimerResult}; @@ -16,6 +20,54 @@ use super::timing_result::TimingResult; use anyhow::{bail, Context, Result}; use statistical::mean; +/// Set CPU affinity and scheduling policy in the child process before exec. +/// This runs after fork() but before exec(). +#[cfg(target_os = "linux")] +fn setup_process_priority( + cpu_affinity: Option, + scheduling_priority: Option, +) -> impl FnMut() -> std::io::Result<()> { + move || { + if let Some(cpu) = cpu_affinity { + unsafe { + let mut set: libc::cpu_set_t = std::mem::zeroed(); + libc::CPU_SET(cpu, &mut set); + if libc::sched_setaffinity(0, std::mem::size_of::(), &set) != 0 { + return Err(std::io::Error::last_os_error()); + } + } + } + + if let Some(policy) = scheduling_priority { + unsafe { + let (sched_policy, priority) = match policy { + SchedulingPolicy::Realtime => (libc::SCHED_FIFO, 99), + SchedulingPolicy::Idle => (libc::SCHED_IDLE, 0), + }; + let param = libc::sched_param { + sched_priority: priority, + }; + if libc::sched_setscheduler(0, sched_policy, ¶m) != 0 { + let err = std::io::Error::last_os_error(); + if err.raw_os_error() == Some(libc::EPERM) { + return Err(std::io::Error::new( + std::io::ErrorKind::PermissionDenied, + format!( + "Permission denied setting {:?} scheduler. \ + Try: sudo setcap cap_sys_nice+ep $(which hyperfine)", + policy + ), + )); + } + return Err(err); + } + } + } + + Ok(()) + } +} + pub enum BenchmarkIteration { NonBenchmarkRun, Warmup(u64), @@ -70,6 +122,8 @@ fn run_command_and_measure_common( command_input_policy: &CommandInputPolicy, command_output_policy: &CommandOutputPolicy, command_name: &str, + cpu_affinity: Option, + scheduling_priority: Option, ) -> Result { let stdin = command_input_policy.get_stdin()?; let (stdout, stderr) = command_output_policy.get_stdout_stderr()?; @@ -90,6 +144,14 @@ fn run_command_and_measure_common( command.env("HYPERFINE_ITERATION", value); } + // Set CPU affinity and scheduling policy in child process before exec + #[cfg(target_os = "linux")] + if cpu_affinity.is_some() || scheduling_priority.is_some() { + unsafe { + command.pre_exec(setup_process_priority(cpu_affinity, scheduling_priority)); + } + } + let result = execute_and_measure(command, until_text) .with_context(|| format!("Failed to run command '{command_name}'"))?; @@ -158,11 +220,14 @@ impl Executor for RawExecutor<'_> { &self.options.command_input_policy, output_policy, &command.get_command_line(), + self.options.cpu_affinity, + self.options.scheduling_priority, )?; Ok(( TimingResult { time_real: result.time_real, + time_real_full: result.time_real_full, time_user: result.time_user, time_system: result.time_system, memory_usage_byte: result.memory_usage_byte, @@ -223,11 +288,14 @@ impl Executor for ShellExecutor<'_> { &self.options.command_input_policy, output_policy, &command.get_command_line(), + self.options.cpu_affinity, + self.options.scheduling_priority, )?; // Subtract shell spawning time if let Some(spawning_time) = self.shell_spawning_time { result.time_real = (result.time_real - spawning_time.time_real).max(0.0); + result.time_real_full = (result.time_real_full - spawning_time.time_real_full).max(0.0); result.time_user = (result.time_user - spawning_time.time_user).max(0.0); result.time_system = (result.time_system - spawning_time.time_system).max(0.0); } @@ -235,6 +303,7 @@ impl Executor for ShellExecutor<'_> { Ok(( TimingResult { time_real: result.time_real, + time_real_full: result.time_real_full, time_user: result.time_user, time_system: result.time_system, memory_usage_byte: result.memory_usage_byte, @@ -298,8 +367,10 @@ impl Executor for ShellExecutor<'_> { bar.finish_and_clear() } + let mean_time_real = mean(×_real); self.shell_spawning_time = Some(TimingResult { - time_real: mean(×_real), + time_real: mean_time_real, + time_real_full: mean_time_real, time_user: mean(×_user), time_system: mean(×_system), memory_usage_byte: 0, @@ -353,9 +424,11 @@ impl Executor for MockExecutor { ExitStatus::from_raw(0) }; + let time_real = Self::extract_time(command.get_command_line()); Ok(( TimingResult { - time_real: Self::extract_time(command.get_command_line()), + time_real, + time_real_full: time_real, time_user: 0.0, time_system: 0.0, memory_usage_byte: 0, diff --git a/src/benchmark/mod.rs b/src/benchmark/mod.rs index e3534a7bc..7259a1416 100644 --- a/src/benchmark/mod.rs +++ b/src/benchmark/mod.rs @@ -12,9 +12,9 @@ use crate::options::{ CmdFailureAction, CommandOutputPolicy, ExecutorKind, Options, OutputStyleOption, }; use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; -use crate::output::format::{format_duration, format_duration_unit}; +use crate::output::format::{format_duration, format_duration_unit, format_memory_value}; use crate::output::progress_bar::get_progress_bar; -use crate::output::warnings::{OutlierWarningOptions, Warnings}; +use crate::output::warnings::{OffCpuSeverity, OutlierWarningOptions, Warnings}; use crate::parameter::ParameterNameAndValue; use crate::util::exit_code::extract_exit_code; use crate::util::min_max::{max, min}; @@ -31,6 +31,15 @@ use self::executor::Executor; /// Threshold for warning about fast execution time pub const MIN_EXECUTION_TIME: Second = 5e-3; +/// Minimum wall time (in seconds) before off-CPU warnings are considered. +/// Below this, timing resolution makes ratio calculations unreliable. +const OFF_CPU_WARNING_MIN_WALL_TIME: Second = 0.005; // 5ms + +/// Ratio thresholds for off-CPU time warnings (wall time / CPU time) +const OFF_CPU_RATIO_NOTE: f64 = 2.0; // 2× triggers a note +const OFF_CPU_RATIO_WARNING: f64 = 3.0; // 3× triggers a warning +const OFF_CPU_RATIO_SEVERE: f64 = 5.0; // 5× triggers severe warning + pub struct Benchmark<'a> { number: usize, command: &'a Command<'a>, @@ -257,8 +266,9 @@ impl<'a> Benchmark<'a> { conclusion_result.map_or(0.0, |res| res.time_real + self.executor.time_overhead()); // Determine number of benchmark runs + // Use time_real_full (includes fork overhead) for scheduling purposes let runs_in_min_time = (self.options.min_benchmarking_time - / (res.time_real + / (res.time_real_full + self.executor.time_overhead() + preparation_overhead + conclusion_overhead)) as u64; @@ -348,6 +358,15 @@ impl<'a> Benchmark<'a> { let user_mean = mean(×_user); let system_mean = mean(×_system); + // Compute memory usage statistics (filter out zero values for platforms that don't support it) + let memory_values: Vec = memory_usage_byte + .iter() + .copied() + .filter(|&m| m > 0) + .collect(); + let memory_min = memory_values.iter().copied().min(); + let memory_max = memory_values.iter().copied().max(); + // Formatting and console output let (mean_str, time_unit) = format_duration_unit(t_mean, self.options.time_unit); let min_str = format_duration(t_min, Some(time_unit)); @@ -389,6 +408,25 @@ impl<'a> Benchmark<'a> { num_str.dimmed() ); } + + // Display memory usage if available (> 0) + if let (Some(mem_min), Some(mem_max)) = (memory_min, memory_max) { + if mem_min == mem_max { + // All runs used the same amount of memory + println!( + " Memory: {}", + format_memory_value(mem_max, Some(8)).yellow() + ); + } else { + println!( + " Memory ({} … {}): {} … {}", + "min".cyan(), + "max".purple(), + format_memory_value(mem_min, Some(8)).cyan(), + format_memory_value(mem_max, Some(8)).purple() + ); + } + } } // Warnings @@ -429,6 +467,30 @@ impl<'a> Benchmark<'a> { warnings.push(Warnings::OutliersDetected(outlier_warning_options)); } + // Check for significant off-CPU time (wall time >> user + system time) + let cpu_time = user_mean + system_mean; + if t_mean >= OFF_CPU_WARNING_MIN_WALL_TIME && cpu_time > 0.0 { + let ratio = t_mean / cpu_time; + let severity = if ratio >= OFF_CPU_RATIO_SEVERE { + Some(OffCpuSeverity::Severe) + } else if ratio >= OFF_CPU_RATIO_WARNING { + Some(OffCpuSeverity::Warning) + } else if ratio >= OFF_CPU_RATIO_NOTE { + Some(OffCpuSeverity::Note) + } else { + None + }; + + if let Some(severity) = severity { + warnings.push(Warnings::OffCpuTimeDetected { + wall_time: t_mean, + cpu_time, + ratio, + severity, + }); + } + } + if !warnings.is_empty() { eprintln!(" "); @@ -455,6 +517,8 @@ impl<'a> Benchmark<'a> { max: t_max, times: Some(times_real), memory_usage_byte: Some(memory_usage_byte), + memory_min, + memory_max, exit_codes, parameters: self .command diff --git a/src/benchmark/relative_speed.rs b/src/benchmark/relative_speed.rs index 90918e527..31c704c91 100644 --- a/src/benchmark/relative_speed.rs +++ b/src/benchmark/relative_speed.rs @@ -134,6 +134,8 @@ fn create_result(name: &str, mean: Scalar) -> BenchmarkResult { max: mean, times: None, memory_usage_byte: None, + memory_min: None, + memory_max: None, exit_codes: Vec::new(), parameters: BTreeMap::new(), } diff --git a/src/benchmark/timing_result.rs b/src/benchmark/timing_result.rs index f7aac92bb..6f798906c 100644 --- a/src/benchmark/timing_result.rs +++ b/src/benchmark/timing_result.rs @@ -3,9 +3,12 @@ use crate::util::units::Second; /// Results from timing a single command #[derive(Debug, Default, Copy, Clone)] pub struct TimingResult { - /// Wall clock time + /// Wall clock time (post-exec on Linux, for reporting) pub time_real: Second, + /// Full wall clock time including fork overhead (for scheduling) + pub time_real_full: Second, + /// Time spent in user mode pub time_user: Second, diff --git a/src/cli.rs b/src/cli.rs index 1986ef6dc..7eb580329 100644 --- a/src/cli.rs +++ b/src/cli.rs @@ -416,6 +416,35 @@ fn build_command() -> Command { .hide(true) .help("Enable debug mode which does not actually run commands, but returns fake times when the command is 'sleep