summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorDavid Peter <mail@david-peter.de>2022-02-21 08:46:10 +0100
committerDavid Peter <mail@david-peter.de>2022-02-21 08:46:10 +0100
commite4da76ec29290189f920025024fc42583a054ca6 (patch)
tree53f5863d4e807f91bccbb6947a8a397bdfa89a12
parentbfb7a15d67c581203410677dfa16583516eafaf6 (diff)
New Benchmark struct
-rw-r--r--src/benchmark/mod.rs514
-rw-r--r--src/benchmark/scheduler.rs504
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(&times_real),
+ time_user: mean(&times_user),
+ time_system: mean(&times_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(&times_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(&times_real);
+ let t_stddev = if times_real.len() > 1 {
+ Some(standard_deviation(&times_real, Some(t_mean)))
+ } else {
+ None
+ };
+ let t_median = median(&times_real);
+ let t_min = min(&times_real);
+ let t_max = max(&times_real);
+
+ let user_mean = mean(&times_user);
+ let system_mean = mean(&times_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(&times_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(&times_real),
- time_user: mean(&times_user),
- time_system: mean(&times_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(&times_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(&times_real);
- let t_stddev = if times_real.len() > 1 {
- Some(standard_deviation(&times_real, Some(t_mean)))
- } else {
- None
- };
- let t_median = median(&times_real);
- let t_min = min(&times_real);
- let t_max = max(&times_real);
-
- let user_mean = mean(&times_user);
- let system_mean = mean(&times_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!(