diff --git a/src/benchmark/executor.rs b/src/benchmark/executor.rs index 59a622f..52284a4 100644 --- a/src/benchmark/executor.rs +++ b/src/benchmark/executor.rs @@ -9,10 +9,9 @@ use crate::options::{ use crate::output::progress_bar::get_progress_bar; use crate::timer::execute_and_measure; use crate::util::randomized_environment_offset; -use crate::util::statistics::mean; use crate::util::units::Second; -use super::measurement::Measurement; +use super::measurement::{Measurement, Measurements}; use anyhow::{bail, Context, Result}; @@ -79,7 +78,7 @@ fn run_command_and_measure_common( let result = execute_and_measure(command) .with_context(|| format!("Failed to run command '{command_name}'"))?; - if !result.status.success() { + if !result.exit_status.success() { use crate::util::exit_code::extract_exit_code; let should_fail = match command_failure_action { @@ -87,7 +86,7 @@ fn run_command_and_measure_common( CmdFailureAction::IgnoreAllFailures => false, CmdFailureAction::IgnoreSpecificFailures(ref codes) => { // Only fail if the exit code is not in the list of codes to ignore - if let Some(exit_code) = extract_exit_code(result.status) { + if let Some(exit_code) = extract_exit_code(result.exit_status) { !codes.contains(&exit_code) } else { // If we can't extract an exit code, treat it as a failure @@ -107,7 +106,7 @@ fn run_command_and_measure_common( bail!( "{cause} in {when}. Use the '-i'/'--ignore-failure' option if you want to ignore this. \ Alternatively, use the '--show-output' option to debug what went wrong.", - cause=result.status.code().map_or( + cause=result.exit_status.code().map_or( "The process has been terminated by a signal".into(), |c| format!("Command terminated with non-zero exit code {c}") @@ -203,7 +202,8 @@ impl Executor for ShellExecutor<'_> { // 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_wall_clock = + (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); } @@ -224,9 +224,7 @@ impl Executor for ShellExecutor<'_> { None }; - let mut times_real: Vec = vec![]; - let mut times_user: Vec = vec![]; - let mut times_system: Vec = vec![]; + let mut measurements = Measurements::default(); for _ in 0..COUNT { // Just run the shell without any command @@ -251,9 +249,7 @@ impl Executor for ShellExecutor<'_> { ); } Ok(r) => { - times_real.push(r.time_real); - times_user.push(r.time_user); - times_system.push(r.time_system); + measurements.push(r); } } @@ -267,18 +263,18 @@ impl Executor for ShellExecutor<'_> { } self.shell_spawning_time = Some(Measurement { - time_real: mean(×_real), - time_user: mean(×_user), - time_system: mean(×_system), - memory_usage_byte: 0, - status: ExitStatus::default(), + time_wall_clock: measurements.time_wall_clock_mean(), + time_user: measurements.time_user_mean(), + time_system: measurements.time_system_mean(), + peak_memory_usage: 0, + exit_status: ExitStatus::default(), }); Ok(()) } fn time_overhead(&self) -> Second { - self.shell_spawning_time.unwrap().time_real + self.shell_spawning_time.unwrap().time_wall_clock } } @@ -311,23 +307,23 @@ impl Executor for MockExecutor { _output_policy: &CommandOutputPolicy, ) -> Result { #[cfg(unix)] - let status = { + let exit_status = { use std::os::unix::process::ExitStatusExt; ExitStatus::from_raw(0) }; #[cfg(windows)] - let status = { + let exit_status = { use std::os::windows::process::ExitStatusExt; ExitStatus::from_raw(0) }; Ok(Measurement { - time_real: Self::extract_time(command.get_command_line()), + time_wall_clock: Self::extract_time(command.get_command_line()), time_user: 0.0, time_system: 0.0, - memory_usage_byte: 0, - status, + peak_memory_usage: 0, + exit_status, }) } diff --git a/src/benchmark/measurement.rs b/src/benchmark/measurement.rs index d724146..4e4efef 100644 --- a/src/benchmark/measurement.rs +++ b/src/benchmark/measurement.rs @@ -1,12 +1,14 @@ use std::process::ExitStatus; +use crate::outlier_detection::modified_zscores; +use crate::util::statistics::{max, mean, median, min, standard_deviation}; use crate::util::units::Second; /// Performance measurements and exit status from running a single command #[derive(Debug, Default, Copy, Clone)] pub struct Measurement { /// Wall clock time - pub time_real: Second, + pub time_wall_clock: Second, /// Time spent in user mode pub time_user: Second, @@ -15,8 +17,77 @@ pub struct Measurement { pub time_system: Second, /// Maximum amount of memory used, in bytes - pub memory_usage_byte: u64, + pub peak_memory_usage: u64, /// The exit status of the process - pub status: ExitStatus, + pub exit_status: ExitStatus, +} + +/// Performance measurements and exit statuses for all runs of a command. +#[derive(Debug, Default, Clone)] +pub struct Measurements { + pub measurements: Vec, +} + +impl Measurements { + pub fn len(&self) -> usize { + self.measurements.len() + } + + pub fn is_empty(&self) -> bool { + self.measurements.is_empty() + } + + pub fn push(&mut self, measurement: Measurement) { + self.measurements.push(measurement); + } + + pub fn wall_clock_times(&self) -> impl Iterator + '_ { + self.measurements.iter().map(|m| m.time_wall_clock) + } + + /// The average wall clock time. + pub fn time_wall_clock_mean(&self) -> Second { + mean(self.wall_clock_times()) + } + + /// The standard deviation of wall clock times, if at least two runs were measured. + pub fn stddev(&self) -> Option { + if self.len() < 2 { + None + } else { + let times: Vec<_> = self.wall_clock_times().collect(); + Some(standard_deviation(×, self.time_wall_clock_mean())) + } + } + + /// The median wall clock time. + pub fn median(&self) -> Second { + median(&self.wall_clock_times().collect::>()) + } + + /// The minimum wall clock time. + pub fn min(&self) -> Second { + min(self.wall_clock_times()) + } + + /// The maximum wall clock time. + pub fn max(&self) -> Second { + max(self.wall_clock_times()) + } + + /// Compute modified Z-scores for the wall clock times. + pub fn modified_zscores(&self) -> Vec { + modified_zscores(&self.wall_clock_times().collect::>()) + } + + /// The average user time. + pub fn time_user_mean(&self) -> Second { + mean(self.measurements.iter().map(|m| m.time_user)) + } + + /// The average system time. + pub fn time_system_mean(&self) -> Second { + mean(self.measurements.iter().map(|m| m.time_system)) + } } diff --git a/src/benchmark/mod.rs b/src/benchmark/mod.rs index fd59224..8f4c1e1 100644 --- a/src/benchmark/mod.rs +++ b/src/benchmark/mod.rs @@ -12,17 +12,16 @@ use crate::command::Command; use crate::options::{ CmdFailureAction, CommandOutputPolicy, ExecutorKind, Options, OutputStyleOption, }; -use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; +use crate::outlier_detection::OUTLIER_THRESHOLD; use crate::output::console_writeln; use crate::output::format::{format_duration, format_duration_unit}; use crate::output::progress_bar::get_progress_bar; use crate::output::warnings::{OutlierWarningOptions, Warnings}; use crate::parameter::ParameterNameAndValue; use crate::util::exit_code::extract_exit_code; -use crate::util::statistics::{max, mean, median, min, standard_deviation}; use crate::util::units::Second; use benchmark_result::BenchmarkResult; -use measurement::Measurement; +use measurement::{Measurement, Measurements}; use anyhow::{anyhow, Result}; use colored::*; @@ -149,11 +148,7 @@ impl<'a> Benchmark<'a> { )?; } - let mut times_real: 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 measurements = Measurements::default(); let mut all_succeeded = true; let output_policy = &self.options.command_output_policies[self.number]; @@ -241,8 +236,9 @@ impl<'a> Benchmark<'a> { }; let preparation_result = run_preparation_command()?; - let preparation_overhead = - preparation_result.map_or(0.0, |res| res.time_real + self.executor.time_overhead()); + let preparation_overhead = preparation_result.map_or(0.0, |res| { + res.time_wall_clock + self.executor.time_overhead() + }); // Initial timing run let res = self.executor.run_command_and_measure( @@ -251,15 +247,16 @@ impl<'a> Benchmark<'a> { None, output_policy, )?; - let success = res.status.success(); + let success = res.exit_status.success(); let conclusion_result = run_conclusion_command()?; - let conclusion_overhead = - conclusion_result.map_or(0.0, |res| res.time_real + self.executor.time_overhead()); + let conclusion_overhead = conclusion_result.map_or(0.0, |res| { + res.time_wall_clock + self.executor.time_overhead() + }); // Determine number of benchmark runs let runs_in_min_time = (self.options.min_benchmarking_time - / (res.time_real + / (res.time_wall_clock + self.executor.time_overhead() + preparation_overhead + conclusion_overhead)) as u64; @@ -278,11 +275,7 @@ impl<'a> Benchmark<'a> { let count_remaining = count - 1; // Save the first result - times_real.push(res.time_real); - 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(res.status)); + measurements.push(res); all_succeeded = all_succeeded && success; @@ -299,7 +292,8 @@ impl<'a> Benchmark<'a> { run_preparation_command()?; let msg = { - let mean = format_duration(mean(×_real), self.options.time_unit); + let mean = + format_duration(measurements.time_wall_clock_mean(), self.options.time_unit); format!("Current estimate: {}", mean.to_string().green()) }; @@ -313,13 +307,9 @@ impl<'a> Benchmark<'a> { None, output_policy, )?; - let success = res.status.success(); + let success = res.exit_status.success(); - times_real.push(res.time_real); - 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(res.status)); + measurements.push(res); all_succeeded = all_succeeded && success; @@ -335,19 +325,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, t_mean)) - } else { - None - }; - let t_median = median(×_real); - let t_min = min(times_real.iter().copied()); - let t_max = max(times_real.iter().copied()); + let t_num = measurements.len(); + let t_mean = measurements.time_wall_clock_mean(); + let t_stddev = measurements.stddev(); + let t_median = measurements.median(); + let t_min = measurements.min(); + let t_max = measurements.max(); - let user_mean = mean(×_user); - let system_mean = mean(×_system); + let user_mean = measurements.time_user_mean(); + let system_mean = measurements.time_system_mean(); // Formatting and console output let (mean_str, time_unit) = format_duration_unit(t_mean, self.options.time_unit); @@ -360,7 +346,7 @@ impl<'a> Benchmark<'a> { if self.options.output_style != OutputStyleOption::Disabled { let mut stdout = io::stdout().lock(); - if times_real.len() == 1 { + if measurements.len() == 1 { console_writeln!( stdout, " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", @@ -401,7 +387,9 @@ impl<'a> Benchmark<'a> { // Check execution time if matches!(self.options.executor_kind, ExecutorKind::Shell(_)) - && times_real.iter().any(|&t| t < MIN_EXECUTION_TIME) + && measurements + .wall_clock_times() + .any(|t| t < MIN_EXECUTION_TIME) { warnings.push(Warnings::FastExecutionTime); } @@ -412,7 +400,7 @@ impl<'a> Benchmark<'a> { } // Run outlier detection - let scores = modified_zscores(×_real); + let scores = measurements.modified_zscores(); let outlier_warning_options = OutlierWarningOptions { warmup_in_use: self.options.warmup_count > 0, @@ -427,7 +415,7 @@ impl<'a> Benchmark<'a> { if scores[0] > OUTLIER_THRESHOLD { warnings.push(Warnings::SlowInitialRun( - times_real[0], + measurements.wall_clock_times().next().unwrap(), outlier_warning_options, )); } else if scores.iter().any(|&s| s.abs() > OUTLIER_THRESHOLD) { @@ -459,9 +447,19 @@ impl<'a> Benchmark<'a> { system: system_mean, min: t_min, max: t_max, - times: Some(times_real), - memory_usage_byte: Some(memory_usage_byte), - exit_codes, + times: Some(measurements.wall_clock_times().collect()), + memory_usage_byte: Some( + measurements + .measurements + .iter() + .map(|m| m.peak_memory_usage) + .collect(), + ), + exit_codes: measurements + .measurements + .iter() + .map(|m| extract_exit_code(m.exit_status)) + .collect(), parameters: self .command .get_parameters() diff --git a/src/timer/mod.rs b/src/timer/mod.rs index 35fa7fc..94357d1 100644 --- a/src/timer/mod.rs +++ b/src/timer/mod.rs @@ -95,16 +95,16 @@ pub fn execute_and_measure(mut command: Command) -> Result { discard(output); } - let status = child.wait()?; + let exit_status = child.wait()?; - let time_real = wallclock_timer.stop(); - let (time_user, time_system, memory_usage_byte) = cpu_timer.stop(); + let time_wall_clock = wallclock_timer.stop(); + let (time_user, time_system, peak_memory_usage) = cpu_timer.stop(); Ok(Measurement { - time_real, + time_wall_clock, time_user, time_system, - memory_usage_byte, - status, + peak_memory_usage, + exit_status, }) } diff --git a/src/util/statistics.rs b/src/util/statistics.rs index 1099caa..443e866 100644 --- a/src/util/statistics.rs +++ b/src/util/statistics.rs @@ -17,8 +17,14 @@ pub fn max(values: impl IntoIterator) -> Q { } /// Arithmetic mean, summing measurements in their original order. -pub fn mean(values: &[f64]) -> f64 { - values.iter().fold(0.0, |sum, value| sum + value) / values.len() as f64 +pub fn mean(values: impl IntoIterator) -> f64 { + let mut sum = 0.0; + let mut count = 0usize; + for value in values { + sum += value; + count += 1; + } + sum / count as f64 } /// Median without modifying the input sample. @@ -86,11 +92,11 @@ mod tests { #[test] fn test_mean() { - assert_eq!(1.0, mean(&[1.0])); - assert_relative_eq!(2.0, mean(&[1.0, 3.0])); + assert_eq!(1.0, mean([1.0])); + assert_relative_eq!(2.0, mean([1.0, 3.0])); let values = [0.1, 0.2, 0.6]; - assert_relative_eq!(mean(&values), 0.3); + assert_relative_eq!(mean(values), 0.3); } #[test] @@ -108,6 +114,6 @@ mod tests { #[test] fn test_standard_deviation() { let values = [0.1, 0.2, 0.3]; - assert_relative_eq!(standard_deviation(&values, mean(&values)), 0.1); + assert_relative_eq!(standard_deviation(&values, mean(values)), 0.1); } }