diff options
author | David Peter <mail@david-peter.de> | 2022-02-21 08:46:10 +0100 |
---|---|---|
committer | David Peter <mail@david-peter.de> | 2022-02-21 08:46:10 +0100 |
commit | e4da76ec29290189f920025024fc42583a054ca6 (patch) | |
tree | 53f5863d4e807f91bccbb6947a8a397bdfa89a12 | |
parent | bfb7a15d67c581203410677dfa16583516eafaf6 (diff) |
New Benchmark struct
-rw-r--r-- | src/benchmark/mod.rs | 514 | ||||
-rw-r--r-- | src/benchmark/scheduler.rs | 504 |
2 files changed, 521 insertions, 497 deletions
diff --git a/src/benchmark/mod.rs b/src/benchmark/mod.rs index 2e6c265..42fc6e1 100644 --- a/src/benchmark/mod.rs +++ b/src/benchmark/mod.rs @@ -3,7 +3,521 @@ pub mod relative_speed; pub mod scheduler; pub mod timing_result; +use std::cmp; +use std::process::{ExitStatus, Stdio}; + +use crate::command::Command; +use crate::options::{CmdFailureAction, CommandOutputPolicy, Options, OutputStyleOption, Shell}; +use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; +use crate::output::format::{format_duration, format_duration_unit}; +use crate::output::progress_bar::get_progress_bar; +use crate::output::warnings::Warnings; +use crate::parameter::ParameterNameAndValue; +use crate::shell::execute_and_time; +use crate::timer::wallclocktimer::WallClockTimer; +use crate::timer::{TimerStart, TimerStop}; +use crate::util::exit_code::extract_exit_code; +use crate::util::min_max::{max, min}; use crate::util::units::Second; +use benchmark_result::BenchmarkResult; +use timing_result::TimingResult; + +use anyhow::{anyhow, bail, Result}; +use colored::*; +use statistical::{mean, median, standard_deviation}; /// Threshold for warning about fast execution time pub const MIN_EXECUTION_TIME: Second = 5e-3; + +/////////////// TODO: refactor the following part + +/// Correct for shell spawning time +fn subtract_shell_spawning_time(time: Second, shell_spawning_time: Second) -> Second { + if time < shell_spawning_time { + 0.0 + } else { + time - shell_spawning_time + } +} + +/// Run the given shell command and measure the execution time +pub fn time_shell_command( + shell: &Shell, + command: &Command<'_>, + command_output_policy: CommandOutputPolicy, + failure_action: CmdFailureAction, + shell_spawning_time: Option<&TimingResult>, +) -> Result<(TimingResult, ExitStatus)> { + let (stdout, stderr) = match command_output_policy { + CommandOutputPolicy::Discard => (Stdio::null(), Stdio::null()), + CommandOutputPolicy::Forward => (Stdio::inherit(), Stdio::inherit()), + }; + + let wallclock_timer = WallClockTimer::start(); + let result = execute_and_time(stdout, stderr, &command.get_shell_command(), shell)?; + let mut time_real = wallclock_timer.stop(); + + let mut time_user = result.user_time; + let mut time_system = result.system_time; + + if failure_action == CmdFailureAction::RaiseError && !result.status.success() { + bail!( + "{}. Use the '-i'/'--ignore-failure' option if you want to ignore this. \ + Alternatively, use the '--show-output' option to debug what went wrong.", + result.status.code().map_or( + "The process has been terminated by a signal".into(), + |c| format!("Command terminated with non-zero exit code: {}", c) + ) + ); + } + + // Correct for shell spawning time + if let Some(spawning_time) = shell_spawning_time { + time_real = subtract_shell_spawning_time(time_real, spawning_time.time_real); + time_user = subtract_shell_spawning_time(time_user, spawning_time.time_user); + time_system = subtract_shell_spawning_time(time_system, spawning_time.time_system); + } + + Ok(( + TimingResult { + time_real, + time_user, + time_system, + }, + result.status, + )) +} + +/// Measure the average shell spawning time +pub fn mean_shell_spawning_time( + shell: &Shell, + style: OutputStyleOption, + command_output_policy: CommandOutputPolicy, +) -> Result<TimingResult> { + const COUNT: u64 = 50; + let progress_bar = if style != OutputStyleOption::Disabled { + Some(get_progress_bar( + COUNT, + "Measuring shell spawning time", + style, + )) + } else { + None + }; + + let mut times_real: Vec<Second> = vec![]; + let mut times_user: Vec<Second> = vec![]; + let mut times_system: Vec<Second> = vec![]; + + for _ in 0..COUNT { + // Just run the shell without any command + let res = time_shell_command( + shell, + &Command::new(None, ""), + command_output_policy, + CmdFailureAction::RaiseError, + None, + ); + + match res { + Err(_) => { + let shell_cmd = if cfg!(windows) { + format!("{} /C \"\"", shell) + } else { + format!("{} -c \"\"", shell) + }; + + bail!( + "Could not measure shell execution time. Make sure you can run '{}'.", + shell_cmd + ); + } + Ok((r, _)) => { + times_real.push(r.time_real); + times_user.push(r.time_user); + times_system.push(r.time_system); + } + } + + if let Some(bar) = progress_bar.as_ref() { + bar.inc(1) + } + } + + if let Some(bar) = progress_bar.as_ref() { + bar.finish_and_clear() + } + + Ok(TimingResult { + time_real: mean(×_real), + time_user: mean(×_user), + time_system: mean(×_system), + }) +} +/////////////// + +pub struct Benchmark<'a> { + number: usize, + command: &'a Command<'a>, + options: &'a Options, + shell_spawning_time: &'a TimingResult, +} + +impl<'a> Benchmark<'a> { + pub fn new( + number: usize, + command: &'a Command<'a>, + options: &'a Options, + shell_spawning_time: &'a TimingResult, + ) -> Self { + Benchmark { + number, + command, + options, + shell_spawning_time, + } + } + + /// Run setup, cleanup, or preparation commands + fn run_intermediate_command( + &self, + command: &Command<'_>, + error_output: &'static str, + ) -> Result<TimingResult> { + time_shell_command( + &self.options.shell, + command, + self.options.command_output_policy, + CmdFailureAction::RaiseError, + None, + ) + .map(|r| r.0) + .map_err(|_| anyhow!(error_output)) + } + + /// Run the command specified by `--setup`. + fn run_setup_command( + &self, + parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, + ) -> Result<TimingResult> { + let command = self + .options + .setup_command + .as_ref() + .map(|setup_command| Command::new_parametrized(None, setup_command, parameters)); + + let error_output = "The setup command terminated with a non-zero exit code. \ + Append ' || true' to the command if you are sure that this can be ignored."; + + Ok(command + .map(|cmd| self.run_intermediate_command(&cmd, error_output)) + .transpose()? + .unwrap_or_default()) + } + + /// Run the command specified by `--cleanup`. + fn run_cleanup_command( + &self, + parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, + ) -> Result<TimingResult> { + let command = self + .options + .cleanup_command + .as_ref() + .map(|cleanup_command| Command::new_parametrized(None, cleanup_command, parameters)); + + let error_output = "The cleanup command terminated with a non-zero exit code. \ + Append ' || true' to the command if you are sure that this can be ignored."; + + Ok(command + .map(|cmd| self.run_intermediate_command(&cmd, error_output)) + .transpose()? + .unwrap_or_default()) + } + + /// Run the command specified by `--prepare`. + fn run_preparation_command(&self, command: &Command<'_>) -> Result<TimingResult> { + let error_output = "The preparation command terminated with a non-zero exit code. \ + Append ' || true' to the command if you are sure that this can be ignored."; + + self.run_intermediate_command(command, error_output) + } + + /// Run the benchmark for a single command + pub fn run(&self) -> Result<BenchmarkResult> { + let command_name = self.command.get_name(); + if self.options.output_style != OutputStyleOption::Disabled { + println!( + "{}{}: {}", + "Benchmark ".bold(), + (self.number + 1).to_string().bold(), + command_name, + ); + } + + let mut times_real: Vec<Second> = vec![]; + let mut times_user: Vec<Second> = vec![]; + let mut times_system: Vec<Second> = vec![]; + let mut exit_codes: Vec<Option<i32>> = vec![]; + let mut all_succeeded = true; + + let preparation_command = self.options.preparation_command.as_ref().map(|values| { + let preparation_command = if values.len() == 1 { + &values[0] + } else { + &values[self.number] + }; + Command::new_parametrized( + None, + preparation_command, + self.command.get_parameters().iter().cloned(), + ) + }); + let run_preparation_command = || { + if let Some(ref cmd) = preparation_command { + self.run_preparation_command(cmd) + } else { + Ok(TimingResult::default()) + } + }; + + self.run_setup_command(self.command.get_parameters().iter().cloned())?; + + // Warmup phase + if self.options.warmup_count > 0 { + let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { + Some(get_progress_bar( + self.options.warmup_count, + "Performing warmup runs", + self.options.output_style, + )) + } else { + None + }; + + for _ in 0..self.options.warmup_count { + let _ = run_preparation_command()?; + let _ = time_shell_command( + &self.options.shell, + self.command, + self.options.command_output_policy, + self.options.command_failure_action, + None, + )?; + if let Some(bar) = progress_bar.as_ref() { + bar.inc(1) + } + } + if let Some(bar) = progress_bar.as_ref() { + bar.finish_and_clear() + } + } + + // Set up progress bar (and spinner for initial measurement) + let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { + Some(get_progress_bar( + self.options.run_bounds.min, + "Initial time measurement", + self.options.output_style, + )) + } else { + None + }; + + let preparation_result = run_preparation_command()?; + + // Initial timing run + let (res, status) = time_shell_command( + &self.options.shell, + self.command, + self.options.command_output_policy, + self.options.command_failure_action, + Some(&self.shell_spawning_time), + )?; + let success = status.success(); + + // Determine number of benchmark runs + let runs_in_min_time = (self.options.min_benchmarking_time + / (res.time_real + preparation_result.time_real + self.shell_spawning_time.time_real)) + as u64; + + let count = { + let min = cmp::max(runs_in_min_time, self.options.run_bounds.min); + + self.options + .run_bounds + .max + .as_ref() + .map(|max| cmp::min(min, *max)) + .unwrap_or(min) + }; + + 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); + exit_codes.push(extract_exit_code(status)); + + all_succeeded = all_succeeded && success; + + // Re-configure the progress bar + if let Some(bar) = progress_bar.as_ref() { + bar.set_length(count) + } + if let Some(bar) = progress_bar.as_ref() { + bar.inc(1) + } + + // Gather statistics (perform the actual benchmark) + for _ in 0..count_remaining { + run_preparation_command()?; + + let msg = { + let mean = format_duration(mean(×_real), self.options.time_unit); + format!("Current estimate: {}", mean.to_string().green()) + }; + + if let Some(bar) = progress_bar.as_ref() { + bar.set_message(msg.to_owned()) + } + + let (res, status) = time_shell_command( + &self.options.shell, + self.command, + self.options.command_output_policy, + self.options.command_failure_action, + Some(self.shell_spawning_time), + )?; + let success = status.success(); + + times_real.push(res.time_real); + times_user.push(res.time_user); + times_system.push(res.time_system); + exit_codes.push(extract_exit_code(status)); + + all_succeeded = all_succeeded && success; + + if let Some(bar) = progress_bar.as_ref() { + bar.inc(1) + } + } + + if let Some(bar) = progress_bar.as_ref() { + bar.finish_and_clear() + } + + // 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))) + } else { + None + }; + let t_median = median(×_real); + let t_min = min(×_real); + let t_max = max(×_real); + + let user_mean = mean(×_user); + let system_mean = mean(×_system); + + // 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)); + let max_str = format_duration(t_max, Some(time_unit)); + let num_str = format!("{} runs", t_num); + + let user_str = format_duration(user_mean, Some(time_unit)); + let system_str = format_duration(system_mean, Some(time_unit)); + + if self.options.output_style != OutputStyleOption::Disabled { + if times_real.len() == 1 { + println!( + " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", + "abs".green().bold(), + mean_str.green().bold(), + " ".to_string(), // alignment + user_str.blue(), + system_str.blue() + ); + } else { + let stddev_str = format_duration(t_stddev.unwrap(), Some(time_unit)); + + println!( + " Time ({} ± {}): {:>8} ± {:>8} [User: {}, System: {}]", + "mean".green().bold(), + "σ".green(), + mean_str.green().bold(), + stddev_str.green(), + user_str.blue(), + system_str.blue() + ); + + println!( + " Range ({} … {}): {:>8} … {:>8} {}", + "min".cyan(), + "max".purple(), + min_str.cyan(), + max_str.purple(), + num_str.dimmed() + ); + } + } + + // Warnings + let mut warnings = vec![]; + + // Check execution time + if times_real.iter().any(|&t| t < MIN_EXECUTION_TIME) { + warnings.push(Warnings::FastExecutionTime); + } + + // Check programm exit codes + if !all_succeeded { + warnings.push(Warnings::NonZeroExitCode); + } + + // Run outlier detection + let scores = modified_zscores(×_real); + if scores[0] > OUTLIER_THRESHOLD { + warnings.push(Warnings::SlowInitialRun(times_real[0])); + } else if scores.iter().any(|&s| s.abs() > OUTLIER_THRESHOLD) { + warnings.push(Warnings::OutliersDetected); + } + + if !warnings.is_empty() { + eprintln!(" "); + + for warning in &warnings { + eprintln!(" {}: {}", "Warning".yellow(), warning); + } + } + + if self.options.output_style != OutputStyleOption::Disabled { + println!(" "); + } + + self.run_cleanup_command(self.command.get_parameters().iter().cloned())?; + + Ok(BenchmarkResult { + command: command_name, + mean: t_mean, + stddev: t_stddev, + median: t_median, + user: user_mean, + system: system_mean, + min: t_min, + max: t_max, + times: Some(times_real), + exit_codes, + parameters: self + .command + .get_parameters() + .iter() + .map(|(name, value)| (name.to_string(), value.to_string())) + .collect(), + }) + } +} diff --git a/src/benchmark/scheduler.rs b/src/benchmark/scheduler.rs index d64778b..9853e2b 100644 --- a/src/benchmark/scheduler.rs +++ b/src/benchmark/scheduler.rs @@ -1,157 +1,13 @@ -use std::cmp; -use std::process::{ExitStatus, Stdio}; - use colored::*; -use statistical::{mean, median, standard_deviation}; use super::benchmark_result::BenchmarkResult; -use super::timing_result::TimingResult; -use super::{relative_speed, MIN_EXECUTION_TIME}; +use super::{relative_speed, Benchmark}; -use crate::command::Command; use crate::command::Commands; use crate::export::ExportManager; -use crate::options::{CmdFailureAction, CommandOutputPolicy, Options, OutputStyleOption, Shell}; -use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; -use crate::output::format::{format_duration, format_duration_unit}; -use crate::output::progress_bar::get_progress_bar; -use crate::output::warnings::Warnings; -use crate::parameter::ParameterNameAndValue; -use crate::shell::execute_and_time; -use crate::timer::wallclocktimer::WallClockTimer; -use crate::timer::{TimerStart, TimerStop}; -use crate::util::exit_code::extract_exit_code; -use crate::util::min_max::{max, min}; -use crate::util::units::Second; - -use anyhow::{anyhow, bail, Result}; - -/////////////// TODO: refactor the following part - -/// Correct for shell spawning time -fn subtract_shell_spawning_time(time: Second, shell_spawning_time: Second) -> Second { - if time < shell_spawning_time { - 0.0 - } else { - time - shell_spawning_time - } -} - -/// Run the given shell command and measure the execution time -pub fn time_shell_command( - shell: &Shell, - command: &Command<'_>, - command_output_policy: CommandOutputPolicy, - failure_action: CmdFailureAction, - shell_spawning_time: Option<TimingResult>, -) -> Result<(TimingResult, ExitStatus)> { - let (stdout, stderr) = match command_output_policy { - CommandOutputPolicy::Discard => (Stdio::null(), Stdio::null()), - CommandOutputPolicy::Forward => (Stdio::inherit(), Stdio::inherit()), - }; - - let wallclock_timer = WallClockTimer::start(); - let result = execute_and_time(stdout, stderr, &command.get_shell_command(), shell)?; - let mut time_real = wallclock_timer.stop(); - - let mut time_user = result.user_time; - let mut time_system = result.system_time; - - if failure_action == CmdFailureAction::RaiseError && !result.status.success() { - bail!( - "{}. Use the '-i'/'--ignore-failure' option if you want to ignore this. \ - Alternatively, use the '--show-output' option to debug what went wrong.", - result.status.code().map_or( - "The process has been terminated by a signal".into(), - |c| format!("Command terminated with non-zero exit code: {}", c) - ) - ); - } - - // Correct for shell spawning time - if let Some(spawning_time) = shell_spawning_time { - time_real = subtract_shell_spawning_time(time_real, spawning_time.time_real); - time_user = subtract_shell_spawning_time(time_user, spawning_time.time_user); - time_system = subtract_shell_spawning_time(time_system, spawning_time.time_system); - } - - Ok(( - TimingResult { - time_real, - time_user, - time_system, - }, - result.status, - )) -} +use crate::options::{Options, OutputStyleOption}; -/// Measure the average shell spawning time -pub fn mean_shell_spawning_time( - shell: &Shell, - style: OutputStyleOption, - command_output_policy: CommandOutputPolicy, -) -> Result<TimingResult> { - const COUNT: u64 = 50; - let progress_bar = if style != OutputStyleOption::Disabled { - Some(get_progress_bar( - COUNT, - "Measuring shell spawning time", - style, - )) - } else { - None - }; - - let mut times_real: Vec<Second> = vec![]; - let mut times_user: Vec<Second> = vec![]; - let mut times_system: Vec<Second> = vec![]; - - for _ in 0..COUNT { - // Just run the shell without any command - let res = time_shell_command( - shell, - &Command::new(None, ""), - command_output_policy, - CmdFailureAction::RaiseError, - None, - ); - - match res { - Err(_) => { - let shell_cmd = if cfg!(windows) { - format!("{} /C \"\"", shell) - } else { - format!("{} -c \"\"", shell) - }; - - bail!( - "Could not measure shell execution time. Make sure you can run '{}'.", - shell_cmd - ); - } - Ok((r, _)) => { - times_real.push(r.time_real); - times_user.push(r.time_user); - times_system.push(r.time_system); - } - } - - if let Some(bar) = progress_bar.as_ref() { - bar.inc(1) - } - } - - if let Some(bar) = progress_bar.as_ref() { - bar.finish_and_clear() - } - - Ok(TimingResult { - time_real: mean(×_real), - time_user: mean(×_user), - time_system: mean(×_system), - }) -} -/////////////// +use anyhow::Result; pub struct Scheduler<'a> { commands: &'a Commands<'a>, @@ -175,15 +31,16 @@ impl<'a> Scheduler<'a> { } pub fn run_benchmarks(&mut self) -> Result<()> { - let shell_spawning_time = mean_shell_spawning_time( + let shell_spawning_time = super::mean_shell_spawning_time( + // TODO &self.options.shell, self.options.output_style, self.options.command_output_policy, )?; - for (benchmark_number, cmd) in self.commands.iter().enumerate() { + for (number, cmd) in self.commands.iter().enumerate() { self.results - .push(self.run_benchmark(benchmark_number, cmd, shell_spawning_time)?); + .push(Benchmark::new(number, cmd, self.options, &shell_spawning_time).run()?); // We export (all results so far) after each individual benchmark, because // we would risk losing all results if a later benchmark fails. @@ -235,351 +92,4 @@ impl<'a> Scheduler<'a> { ); } } - - /// Run setup, cleanup, or preparation commands - fn run_intermediate_command( - &self, - command: &Command<'_>, - error_output: &'static str, - ) -> Result<TimingResult> { - time_shell_command( - &self.options.shell, - command, - self.options.command_output_policy, - CmdFailureAction::RaiseError, - None, - ) - .map(|r| r.0) - .map_err(|_| anyhow!(error_output)) - } - - /// Run the command specified by `--setup`. - fn run_setup_command( - &self, - parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, - ) -> Result<TimingResult> { - let command = self - .options - .setup_command - .as_ref() - .map(|setup_command| Command::new_parametrized(None, setup_command, parameters)); - - let error_output = "The setup command terminated with a non-zero exit code. \ - Append ' || true' to the command if you are sure that this can be ignored."; - - Ok(command - .map(|cmd| self.run_intermediate_command(&cmd, error_output)) - .transpose()? - .unwrap_or_default()) - } - - /// Run the command specified by `--cleanup`. - fn run_cleanup_command( - &self, - parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, - ) -> Result<TimingResult> { - let command = self - .options - .cleanup_command - .as_ref() - .map(|cleanup_command| Command::new_parametrized(None, cleanup_command, parameters)); - - let error_output = "The cleanup command terminated with a non-zero exit code. \ - Append ' || true' to the command if you are sure that this can be ignored."; - - Ok(command - .map(|cmd| self.run_intermediate_command(&cmd, error_output)) - .transpose()? - .unwrap_or_default()) - } - - /// Run the command specified by `--prepare`. - fn run_preparation_command(&self, command: &Command<'_>) -> Result<TimingResult> { - let error_output = "The preparation command terminated with a non-zero exit code. \ - Append ' || true' to the command if you are sure that this can be ignored."; - - self.run_intermediate_command(command, error_output) - } - - /// Run the benchmark for a single command - pub fn run_benchmark( - &self, - benchmark_number: usize, - command: &Command<'_>, - shell_spawning_time: TimingResult, - ) -> Result<BenchmarkResult> { - let command_name = command.get_name(); - if self.options.output_style != OutputStyleOption::Disabled { - println!( - "{}{}: {}", - "Benchmark ".bold(), - (benchmark_number + 1).to_string().bold(), - command_name, - ); - } - - let mut times_real: Vec<Second> = vec![]; - let mut times_user: Vec<Second> = vec![]; - let mut times_system: Vec<Second> = vec![]; - let mut exit_codes: Vec<Option<i32>> = vec![]; - let mut all_succeeded = true; - - let preparation_command = self.options.preparation_command.as_ref().map(|values| { - let preparation_command = if values.len() == 1 { - &values[0] - } else { - &values[benchmark_number] - }; - Command::new_parametrized( - None, - preparation_command, - command.get_parameters().iter().cloned(), - ) - }); - let run_preparation_command = || { - if let Some(ref cmd) = preparation_command { - self.run_preparation_command(cmd) - } else { - Ok(TimingResult::default()) - } - }; - - self.run_setup_command(command.get_parameters().iter().cloned())?; - - // Warmup phase - if self.options.warmup_count > 0 { - let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { - Some(get_progress_bar( - self.options.warmup_count, - "Performing warmup runs", - self.options.output_style, - )) - } else { - None - }; - - for _ in 0..self.options.warmup_count { - let _ = run_preparation_command()?; - let _ = time_shell_command( - &self.options.shell, - command, - self.options.command_output_policy, - self.options.command_failure_action, - None, - )?; - if let Some(bar) = progress_bar.as_ref() { - bar.inc(1) - } - } - if let Some(bar) = progress_bar.as_ref() { - bar.finish_and_clear() - } - } - - // Set up progress bar (and spinner for initial measurement) - let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { - Some(get_progress_bar( - self.options.run_bounds.min, - "Initial time measurement", - self.options.output_style, - )) - } else { - None - }; - - let preparation_result = run_preparation_command()?; - - // Initial timing run - let (res, status) = time_shell_command( - &self.options.shell, - command, - self.options.command_output_policy, - self.options.command_failure_action, - Some(shell_spawning_time), - )?; - let success = status.success(); - - // Determine number of benchmark runs - let runs_in_min_time = (self.options.min_benchmarking_time - / (res.time_real + preparation_result.time_real + shell_spawning_time.time_real)) - as u64; - - let count = { - let min = cmp::max(runs_in_min_time, self.options.run_bounds.min); - - self.options - .run_bounds - .max - .as_ref() - .map(|max| cmp::min(min, *max)) - .unwrap_or(min) - }; - - 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); - exit_codes.push(extract_exit_code(status)); - - all_succeeded = all_succeeded && success; - - // Re-configure the progress bar - if let Some(bar) = progress_bar.as_ref() { - bar.set_length(count) - } - if let Some(bar) = progress_bar.as_ref() { - bar.inc(1) - } - - // Gather statistics (perform the actual benchmark) - for _ in 0..count_remaining { - run_preparation_command()?; - - let msg = { - let mean = format_duration(mean(×_real), self.options.time_unit); - format!("Current estimate: {}", mean.to_string().green()) - }; - - if let Some(bar) = progress_bar.as_ref() { - bar.set_message(msg.to_owned()) - } - - let (res, status) = time_shell_command( - &self.options.shell, - command, - self.options.command_output_policy, - self.options.command_failure_action, - Some(shell_spawning_time), - )?; - let success = status.success(); - - times_real.push(res.time_real); - times_user.push(res.time_user); - times_system.push(res.time_system); - exit_codes.push(extract_exit_code(status)); - - all_succeeded = all_succeeded && success; - - if let Some(bar) = progress_bar.as_ref() { - bar.inc(1) - } - } - - if let Some(bar) = progress_bar.as_ref() { - bar.finish_and_clear() - } - - // 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))) - } else { - None - }; - let t_median = median(×_real); - let t_min = min(×_real); - let t_max = max(×_real); - - let user_mean = mean(×_user); - let system_mean = mean(×_system); - - // 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)); - let max_str = format_duration(t_max, Some(time_unit)); - let num_str = format!("{} runs", t_num); - - let user_str = format_duration(user_mean, Some(time_unit)); - let system_str = format_duration(system_mean, Some(time_unit)); - - if self.options.output_style != OutputStyleOption::Disabled { - if times_real.len() == 1 { - println!( - " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", - "abs".green().bold(), - mean_str.green().bold(), - " ".to_string(), // alignment - user_str.blue(), - system_str.blue() - ); - } else { - let stddev_str = format_duration(t_stddev.unwrap(), Some(time_unit)); - - println!( - " Time ({} ± {}): {:>8} ± {:>8} [User: {}, System: {}]", - "mean".green().bold(), - "σ".green(), - mean_str.green().bold(), - stddev_str.green(), - user_str.blue(), - system_str.blue() - ); - - println!( |