From c20fcc0bda8045bee6e71a88d078fed6a83882c8 Mon Sep 17 00:00:00 2001 From: David Peter Date: Mon, 5 Oct 2026 14:14:51 +0200 Subject: [PATCH] Real => wall clock --- src/benchmark/benchmark_result.rs | 12 +++--- src/benchmark/executor.rs | 67 +++++++++++++++++++++---------- src/benchmark/mod.rs | 66 +++++++++++++++--------------- src/benchmark/relative_speed.rs | 4 +- src/export/csv.rs | 14 +++---- src/export/tests.rs | 50 +++++++++++------------ src/timer/mod.rs | 6 +-- 7 files changed, 122 insertions(+), 97 deletions(-) diff --git a/src/benchmark/benchmark_result.rs b/src/benchmark/benchmark_result.rs index 9210501..4712032 100644 --- a/src/benchmark/benchmark_result.rs +++ b/src/benchmark/benchmark_result.rs @@ -8,8 +8,9 @@ use crate::util::{ units::Second, }; +/// Performance metrics and exit codes for each run #[derive(Debug, Default, Clone, Serialize, PartialEq)] -pub struct BenchmarkRun { +pub struct Run { /// Wall clock time measurement pub wall_clock_time: Second, @@ -26,15 +27,14 @@ pub struct BenchmarkRun { pub exit_code: Option, } +/// Parameter value and whether it was used in the command line template #[derive(Debug, Default, Clone, Serialize, PartialEq)] pub struct Parameter { pub value: String, pub is_unused: bool, } -/// Set of values that will be exported. -// NOTE: `serde` is used for JSON serialization, but not for CSV serialization due to the -// `parameters` map. Update `src/hyperfine/export/csv.rs` with new fields, as appropriate. +/// Meta data and performance metrics for a single benchmark #[derive(Debug, Default, Clone, Serialize, PartialEq)] #[serde(transparent)] pub struct Parameter { @@ -49,8 +49,8 @@ pub struct BenchmarkResult { /// The full command line of the program that is being benchmarked pub command: String, - /// All run time measurements - pub runs: Vec, + /// Performance metrics and exit codes for each run + pub runs: Vec, /// Parameter values for this benchmark #[serde(skip_serializing_if = "BTreeMap::is_empty")] diff --git a/src/benchmark/executor.rs b/src/benchmark/executor.rs index e450d40..afc8405 100644 --- a/src/benchmark/executor.rs +++ b/src/benchmark/executor.rs @@ -144,7 +144,17 @@ impl Executor for RawExecutor<'_> { &self.options.command_input_policy, output_policy, &command.get_command_line(), - ) + )?; + + Ok(( + TimingResult { + time_wall_clock: result.time_wall_clock, + time_user: result.time_user, + time_system: result.time_system, + memory_usage_byte: result.memory_usage_byte, + }, + result.status, + )) } fn calibrate(&mut self) -> Result<()> { @@ -204,12 +214,20 @@ impl Executor for ShellExecutor<'_> { // Subtract shell spawning time if let Some(spawning_time) = self.shell_spawning_time { result.time_wall_clock = - (result.time_wall_clock - spawning_time.time_wall_clock).max(Time::zero()); - result.time_user = (result.time_user - spawning_time.time_user).max(Time::zero()); - result.time_system = (result.time_system - spawning_time.time_system).max(Time::zero()); + (result.time_wall_clock - spawning_time.time_wall_clock).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); } - Ok(result) + Ok(( + TimingResult { + time_wall_clock: result.time_wall_clock, + time_user: result.time_user, + time_system: result.time_system, + memory_usage_byte: result.memory_usage_byte, + }, + result.status, + )) } /// Measure the average shell spawning time @@ -225,7 +243,9 @@ impl Executor for ShellExecutor<'_> { None }; - let mut measurements = Measurements::default(); + let mut times_wall_clock: Vec = vec![]; + let mut times_user: Vec = vec![]; + let mut times_system: Vec = vec![]; for _ in 0..COUNT { // Just run the shell without any command @@ -249,8 +269,10 @@ impl Executor for ShellExecutor<'_> { shell_cmd ); } - Ok(r) => { - measurements.push(r); + Ok((r, _)) => { + times_wall_clock.push(r.time_wall_clock); + times_user.push(r.time_user); + times_system.push(r.time_system); } } @@ -263,18 +285,17 @@ impl Executor for ShellExecutor<'_> { bar.finish_and_clear() } - self.shell_spawning_time = Some(Measurement { - time_wall_clock: measurements.time_wall_clock_mean(), - time_user: measurements.time_user_mean(), - time_system: measurements.time_system_mean(), - peak_memory_usage: measurements.peak_memory_usage_mean(), - exit_status: ExitStatus::default(), + self.shell_spawning_time = Some(TimingResult { + time_wall_clock: mean(×_wall_clock), + time_user: mean(×_user), + time_system: mean(×_system), + memory_usage_byte: 0, }); Ok(()) } - fn time_overhead(&self) -> Time { + fn time_overhead(&self) -> Second { self.shell_spawning_time.unwrap().time_wall_clock } } @@ -321,13 +342,15 @@ impl Executor for MockExecutor { ExitStatus::from_raw(0) }; - Ok(Measurement { - time_wall_clock: Self::extract_time(command.get_command_line()), - time_user: Time::zero(), - time_system: Time::zero(), - peak_memory_usage: Information::zero(), - exit_status, - }) + Ok(( + TimingResult { + time_wall_clock: Self::extract_time(command.get_command_line()), + time_user: 0.0, + time_system: 0.0, + memory_usage_byte: 0, + }, + status, + )) } fn calibrate(&mut self) -> Result<()> { diff --git a/src/benchmark/mod.rs b/src/benchmark/mod.rs index db9a550..88347ec 100644 --- a/src/benchmark/mod.rs +++ b/src/benchmark/mod.rs @@ -8,7 +8,7 @@ use std::cmp; use std::io::{self, Write}; use std::time::Instant; -use crate::benchmark::benchmark_result::{BenchmarkRun, Parameter}; +use crate::benchmark::benchmark_result::{Parameter, Run}; use crate::benchmark::executor::BenchmarkIteration; use crate::command::Command; use crate::options::{ @@ -168,7 +168,11 @@ impl<'a> Benchmark<'a> { )?; } - let mut measurements = Measurements::default(); + let mut times_wall_clock: Vec = vec![]; + let mut times_user: Vec = vec![]; + let mut times_system: Vec = vec![]; + let mut memory_usage_byte: Vec = vec![]; + let mut exit_codes: Vec> = vec![]; let mut all_succeeded = true; let output_policy = &self.options.command_output_policies[self.number]; @@ -260,9 +264,8 @@ impl<'a> Benchmark<'a> { None }; - let benchmark_iteration = BenchmarkIteration::Benchmark(0); - let preparation_result = run_preparation_command(benchmark_iteration)?; - let preparation_overhead = preparation_result.map_or(Time::zero(), |res| { + let preparation_result = run_preparation_command()?; + let preparation_overhead = preparation_result.map_or(0.0, |res| { res.time_wall_clock + self.executor.time_overhead() }); @@ -290,8 +293,8 @@ impl<'a> Benchmark<'a> { ); } - let conclusion_result = run_conclusion_command(benchmark_iteration)?; - let conclusion_overhead = conclusion_result.map_or(Time::zero(), |res| { + let conclusion_result = run_conclusion_command()?; + let conclusion_overhead = conclusion_result.map_or(0.0, |res| { res.time_wall_clock + self.executor.time_overhead() }); @@ -317,7 +320,11 @@ impl<'a> Benchmark<'a> { let count_remaining = count - 1; // Save the first result - measurements.push(res); + times_wall_clock.push(res.time_wall_clock); + times_user.push(res.time_user); + times_system.push(res.time_system); + memory_usage_byte.push(res.memory_usage_byte); + exit_codes.push(extract_exit_code(status)); all_succeeded = all_succeeded && success; @@ -332,12 +339,7 @@ impl<'a> Benchmark<'a> { let benchmark_iteration = BenchmarkIteration::Benchmark(i + 1); let msg = { - let t_wall_clock_mean = measurements.time_wall_clock_mean(); - let time_unit = self - .options - .time_unit - .unwrap_or(t_wall_clock_mean.suitable_unit()); - let mean = t_wall_clock_mean.format(time_unit); + let mean = format_duration(mean(×_wall_clock), self.options.time_unit); format!("Current estimate: {}", mean.to_string().green()) }; @@ -355,7 +357,11 @@ impl<'a> Benchmark<'a> { )?; let success = res.exit_status.success(); - measurements.push(res); + times_wall_clock.push(res.time_wall_clock); + times_user.push(res.time_user); + times_system.push(res.time_system); + memory_usage_byte.push(res.memory_usage_byte); + exit_codes.push(extract_exit_code(status)); all_succeeded = all_succeeded && success; @@ -371,15 +377,15 @@ impl<'a> Benchmark<'a> { } // Compute statistical quantities - let t_num = times_real.len(); - let t_mean = mean(×_real); - let t_stddev = if times_real.len() > 1 { - Some(standard_deviation(×_real, Some(t_mean))) + let t_num = times_wall_clock.len(); + let t_mean = mean(×_wall_clock); + let t_stddev = if times_wall_clock.len() > 1 { + Some(standard_deviation(×_wall_clock, Some(t_mean))) } else { None }; - let t_min = min(×_real); - let t_max = max(×_real); + let t_min = min(×_wall_clock); + let t_max = max(×_wall_clock); let user_mean = measurements.time_user_mean(); let system_mean = measurements.time_system_mean(); @@ -395,10 +401,8 @@ impl<'a> Benchmark<'a> { let system_str = system_mean.format(time_unit); if self.options.output_style != OutputStyleOption::Disabled { - let mut stdout = io::stdout().lock(); - if measurements.len() == 1 { - console_writeln!( - stdout, + if times_wall_clock.len() == 1 { + println!( " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", "abs".green().bold(), mean_str.green().bold(), @@ -437,9 +441,7 @@ impl<'a> Benchmark<'a> { // Check execution time if matches!(self.options.executor_kind, ExecutorKind::Shell(_)) - && measurements - .wall_clock_times() - .any(|t| t < MIN_EXECUTION_TIME) + && times_wall_clock.iter().any(|&t| t < MIN_EXECUTION_TIME) { warnings.push(Warnings::FastExecutionTime); } @@ -450,7 +452,7 @@ impl<'a> Benchmark<'a> { } // Run outlier detection - let scores = measurements.modified_zscores(); + let scores = modified_zscores(×_wall_clock); let outlier_warning_options = OutlierWarningOptions { warmup_in_use: self.options.warmup_count > 0, @@ -465,7 +467,7 @@ impl<'a> Benchmark<'a> { if scores[0] > OUTLIER_THRESHOLD { warnings.push(Warnings::SlowInitialRun( - measurements.wall_clock_times().next().unwrap(), + times_wall_clock[0], outlier_warning_options, )); } else if scores.iter().any(|&s| s.abs() > OUTLIER_THRESHOLD) { @@ -489,7 +491,7 @@ impl<'a> Benchmark<'a> { Ok(BenchmarkResult { command: self.command.get_name(), - runs: times_real + runs: times_wall_clock .iter() .zip(times_user.iter()) .zip(times_system.iter()) @@ -500,7 +502,7 @@ impl<'a> Benchmark<'a> { (((wall_clock_time, user_time), system_time), memory_usage_byte), exit_code, )| { - BenchmarkRun { + Run { wall_clock_time: *wall_clock_time, user_time: *user_time, system_time: *system_time, diff --git a/src/benchmark/relative_speed.rs b/src/benchmark/relative_speed.rs index 71d63da..2dc300c 100644 --- a/src/benchmark/relative_speed.rs +++ b/src/benchmark/relative_speed.rs @@ -147,11 +147,11 @@ pub fn compute<'a>( fn create_result(name: &str, mean: f64) -> BenchmarkResult { use std::collections::BTreeMap; - use crate::benchmark::benchmark_result::BenchmarkRun; + use crate::benchmark::benchmark_result::Run; BenchmarkResult { command: name.into(), - runs: vec![BenchmarkRun { + runs: vec![Run { wall_clock_time: mean, user_time: mean, system_time: 0., diff --git a/src/export/csv.rs b/src/export/csv.rs index fcd782d..4c961ce 100644 --- a/src/export/csv.rs +++ b/src/export/csv.rs @@ -68,7 +68,7 @@ impl Exporter for CsvExporter { } #[cfg(test)] -use crate::benchmark::benchmark_result::{BenchmarkRun, Parameter}; +use crate::benchmark::benchmark_result::{Parameter, Run}; #[test] fn test_csv() { @@ -85,21 +85,21 @@ fn test_csv() { BenchmarkResult { command: String::from("command_a"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 7.0, user_time: 7.0, system_time: 0.0, memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 8.0, user_time: 8.0, system_time: 0.0, memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 12.0, user_time: 12.0, system_time: 0.0, @@ -129,21 +129,21 @@ fn test_csv() { BenchmarkResult { command: String::from("command_b"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 17.0, user_time: 17.0, system_time: 0.0, memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 18.0, user_time: 18.0, system_time: 0.0, memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 19.0, user_time: 19.0, system_time: 0.0, diff --git a/src/export/tests.rs b/src/export/tests.rs index 2c303d2..0f3ed15 100644 --- a/src/export/tests.rs +++ b/src/export/tests.rs @@ -1,5 +1,5 @@ use super::Exporter; -use crate::benchmark::benchmark_result::{BenchmarkResult, BenchmarkRun}; +use crate::benchmark::benchmark_result::{BenchmarkResult, Run}; use crate::export::asciidoc::AsciidocExporter; use crate::export::orgmode::OrgmodeExporter; use crate::quantity::{byte, second, Information, Time, TimeUnit, Zero}; @@ -28,21 +28,21 @@ fn test_markup_export_auto_ms() { BenchmarkResult { command: String::from("sleep 0.1"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 0.09, user_time: 0.09, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.10, user_time: 0.10, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.14, user_time: 0.14, system_time: 0., @@ -55,21 +55,21 @@ fn test_markup_export_auto_ms() { BenchmarkResult { command: String::from("sleep 2"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 2.0, user_time: 2.0, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 3.0, user_time: 3.0, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 4.0, user_time: 4.0, system_time: 0., @@ -127,21 +127,21 @@ fn test_markup_export_auto_s() { BenchmarkResult { command: String::from("sleep 2"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 2.1, user_time: 2.1, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.2, user_time: 2.2, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.3, user_time: 2.3, system_time: 0., @@ -154,21 +154,21 @@ fn test_markup_export_auto_s() { BenchmarkResult { command: String::from("sleep 0.1"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 0.1, user_time: 0.1, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.2, user_time: 0.2, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.3, user_time: 0.3, system_time: 0., @@ -226,21 +226,21 @@ fn test_markup_export_manual_ms() { BenchmarkResult { command: String::from("sleep 2"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 2.1, user_time: 2.1, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.2, user_time: 2.2, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.3, user_time: 2.3, system_time: 0., @@ -253,21 +253,21 @@ fn test_markup_export_manual_ms() { BenchmarkResult { command: String::from("sleep 0.1"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 0.1, user_time: 0.1, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.2, user_time: 0.2, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.3, user_time: 0.3, system_time: 0., @@ -324,21 +324,21 @@ fn test_markup_export_manual_s() { BenchmarkResult { command: String::from("sleep 2"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 2.01, user_time: 2.01, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.02, user_time: 2.02, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 2.03, user_time: 2.03, system_time: 0., @@ -351,21 +351,21 @@ fn test_markup_export_manual_s() { BenchmarkResult { command: String::from("sleep 0.1"), runs: vec![ - BenchmarkRun { + Run { wall_clock_time: 0.11, user_time: 0.11, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.12, user_time: 0.12, system_time: 0., memory_usage_byte: 1024, exit_code: Some(0), }, - BenchmarkRun { + Run { wall_clock_time: 0.13, user_time: 0.13, system_time: 0., diff --git a/src/timer/mod.rs b/src/timer/mod.rs index 9b7df54..15dbc8b 100644 --- a/src/timer/mod.rs +++ b/src/timer/mod.rs @@ -27,7 +27,7 @@ use anyhow::Result; /// Used to indicate the result of running a command #[derive(Debug, Copy, Clone)] pub struct TimerResult { - pub time_real: Second, + pub time_wall_clock: Second, pub time_user: Second, pub time_system: Second, pub memory_usage_byte: u64, @@ -94,9 +94,9 @@ pub fn execute_and_measure(mut command: Command) -> Result { } let (status, time_user, time_system, memory_usage_byte) = cpu_timer.stop(child)?; - let time_real = wallclock_timer.stop(); + let time_wall_clock = wallclock_timer.stop(); - Ok(Measurement { + Ok(TimerResult { time_wall_clock, time_user, time_system,