mirror of
https://github.com/sharkdp/hyperfine.git
synced 2024-09-11 14:07:02 +03:00
New Benchmark struct
This commit is contained in:
David Peter
David Peter
parent
d3c7c7974a
commit
5c9c8c2383
@ -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(),
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
@ -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 crate::options::{Options, OutputStyleOption};
|
||||
|
||||
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,
|
||||
))
|
||||
}
|
||||
|
||||
/// 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!(
|
||||
" 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(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: command
|
||||
.get_parameters()
|
||||
.iter()
|
||||
.map(|(name, value)| (name.to_string(), value.to_string()))
|
||||
.collect(),
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
Loading…
Reference in New Issue
Block a user