mod.rs
1 pub mod benchmark_result; 2 pub mod executor; 3 pub mod relative_speed; 4 pub mod scheduler; 5 pub mod timing_result; 6 7 use std::cmp; 8 9 use crate::benchmark::executor::BenchmarkIteration; 10 use crate::command::Command; 11 use crate::options::{ 12 CmdFailureAction, CommandOutputPolicy, ExecutorKind, Options, OutputStyleOption, 13 }; 14 use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; 15 use crate::output::format::{format_duration, format_duration_unit}; 16 use crate::output::progress_bar::get_progress_bar; 17 use crate::output::warnings::{OutlierWarningOptions, Warnings}; 18 use crate::parameter::ParameterNameAndValue; 19 use crate::util::exit_code::extract_exit_code; 20 use crate::util::min_max::{max, min}; 21 use crate::util::units::Second; 22 use benchmark_result::BenchmarkResult; 23 use timing_result::TimingResult; 24 25 use anyhow::{anyhow, Result}; 26 use colored::*; 27 use statistical::{mean, median, standard_deviation}; 28 29 use self::executor::Executor; 30 31 /// Threshold for warning about fast execution time 32 pub const MIN_EXECUTION_TIME: Second = 5e-3; 33 34 pub struct Benchmark<'a> { 35 number: usize, 36 command: &'a Command<'a>, 37 options: &'a Options, 38 executor: &'a dyn Executor, 39 } 40 41 impl<'a> Benchmark<'a> { 42 pub fn new( 43 number: usize, 44 command: &'a Command<'a>, 45 options: &'a Options, 46 executor: &'a dyn Executor, 47 ) -> Self { 48 Benchmark { 49 number, 50 command, 51 options, 52 executor, 53 } 54 } 55 56 /// Run setup, cleanup, or preparation commands 57 fn run_intermediate_command( 58 &self, 59 command: &Command<'_>, 60 error_output: &'static str, 61 output_policy: &CommandOutputPolicy, 62 ) -> Result<TimingResult> { 63 self.executor 64 .run_command_and_measure( 65 command, 66 executor::BenchmarkIteration::NonBenchmarkRun, 67 Some(CmdFailureAction::RaiseError), 68 output_policy, 69 ) 70 .map(|r| r.0) 71 .map_err(|_| anyhow!(error_output)) 72 } 73 74 /// Run the command specified by `--setup`. 75 fn run_setup_command( 76 &self, 77 parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, 78 output_policy: &CommandOutputPolicy, 79 ) -> Result<TimingResult> { 80 let command = self 81 .options 82 .setup_command 83 .as_ref() 84 .map(|setup_command| Command::new_parametrized(None, setup_command, parameters)); 85 86 let error_output = "The setup command terminated with a non-zero exit code. \ 87 Append ' || true' to the command if you are sure that this can be ignored."; 88 89 Ok(command 90 .map(|cmd| self.run_intermediate_command(&cmd, error_output, output_policy)) 91 .transpose()? 92 .unwrap_or_default()) 93 } 94 95 /// Run the command specified by `--cleanup`. 96 fn run_cleanup_command( 97 &self, 98 parameters: impl IntoIterator<Item = ParameterNameAndValue<'a>>, 99 output_policy: &CommandOutputPolicy, 100 ) -> Result<TimingResult> { 101 let command = self 102 .options 103 .cleanup_command 104 .as_ref() 105 .map(|cleanup_command| Command::new_parametrized(None, cleanup_command, parameters)); 106 107 let error_output = "The cleanup command terminated with a non-zero exit code. \ 108 Append ' || true' to the command if you are sure that this can be ignored."; 109 110 Ok(command 111 .map(|cmd| self.run_intermediate_command(&cmd, error_output, output_policy)) 112 .transpose()? 113 .unwrap_or_default()) 114 } 115 116 /// Run the command specified by `--prepare`. 117 fn run_preparation_command( 118 &self, 119 command: &Command<'_>, 120 output_policy: &CommandOutputPolicy, 121 ) -> Result<TimingResult> { 122 let error_output = "The preparation command terminated with a non-zero exit code. \ 123 Append ' || true' to the command if you are sure that this can be ignored."; 124 125 self.run_intermediate_command(command, error_output, output_policy) 126 } 127 128 /// Run the command specified by `--conclude`. 129 fn run_conclusion_command( 130 &self, 131 command: &Command<'_>, 132 output_policy: &CommandOutputPolicy, 133 ) -> Result<TimingResult> { 134 let error_output = "The conclusion command terminated with a non-zero exit code. \ 135 Append ' || true' to the command if you are sure that this can be ignored."; 136 137 self.run_intermediate_command(command, error_output, output_policy) 138 } 139 140 /// Run the benchmark for a single command 141 pub fn run(&self) -> Result<BenchmarkResult> { 142 if self.options.output_style != OutputStyleOption::Disabled { 143 println!( 144 "{}{}: {}", 145 "Benchmark ".bold(), 146 (self.number + 1).to_string().bold(), 147 self.command.get_name_with_unused_parameters(), 148 ); 149 } 150 151 let mut times_real: Vec<Second> = vec![]; 152 let mut times_user: Vec<Second> = vec![]; 153 let mut times_system: Vec<Second> = vec![]; 154 let mut memory_usage_byte: Vec<u64> = vec![]; 155 let mut exit_codes: Vec<Option<i32>> = vec![]; 156 let mut all_succeeded = true; 157 158 let output_policy = &self.options.command_output_policies[self.number]; 159 160 let preparation_command = self.options.preparation_command.as_ref().map(|values| { 161 let preparation_command = if values.len() == 1 { 162 &values[0] 163 } else { 164 &values[self.number] 165 }; 166 Command::new_parametrized( 167 None, 168 preparation_command, 169 self.command.get_parameters().iter().cloned(), 170 ) 171 }); 172 173 let run_preparation_command = || { 174 preparation_command 175 .as_ref() 176 .map(|cmd| self.run_preparation_command(cmd, output_policy)) 177 .transpose() 178 }; 179 180 let conclusion_command = self.options.conclusion_command.as_ref().map(|values| { 181 let conclusion_command = if values.len() == 1 { 182 &values[0] 183 } else { 184 &values[self.number] 185 }; 186 Command::new_parametrized( 187 None, 188 conclusion_command, 189 self.command.get_parameters().iter().cloned(), 190 ) 191 }); 192 let run_conclusion_command = || { 193 conclusion_command 194 .as_ref() 195 .map(|cmd| self.run_conclusion_command(cmd, output_policy)) 196 .transpose() 197 }; 198 199 self.run_setup_command(self.command.get_parameters().iter().cloned(), output_policy)?; 200 201 // Warmup phase 202 if self.options.warmup_count > 0 { 203 let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { 204 Some(get_progress_bar( 205 self.options.warmup_count, 206 "Performing warmup runs", 207 self.options.output_style, 208 )) 209 } else { 210 None 211 }; 212 213 for i in 0..self.options.warmup_count { 214 let _ = run_preparation_command()?; 215 let _ = self.executor.run_command_and_measure( 216 self.command, 217 BenchmarkIteration::Warmup(i), 218 None, 219 output_policy, 220 )?; 221 let _ = run_conclusion_command()?; 222 if let Some(bar) = progress_bar.as_ref() { 223 bar.inc(1) 224 } 225 } 226 if let Some(bar) = progress_bar.as_ref() { 227 bar.finish_and_clear() 228 } 229 } 230 231 // Set up progress bar (and spinner for initial measurement) 232 let progress_bar = if self.options.output_style != OutputStyleOption::Disabled { 233 Some(get_progress_bar( 234 self.options.run_bounds.min, 235 "Initial time measurement", 236 self.options.output_style, 237 )) 238 } else { 239 None 240 }; 241 242 let preparation_result = run_preparation_command()?; 243 let preparation_overhead = 244 preparation_result.map_or(0.0, |res| res.time_real + self.executor.time_overhead()); 245 246 // Initial timing run 247 let (res, status) = self.executor.run_command_and_measure( 248 self.command, 249 BenchmarkIteration::Benchmark(0), 250 None, 251 output_policy, 252 )?; 253 let success = status.success(); 254 255 let conclusion_result = run_conclusion_command()?; 256 let conclusion_overhead = 257 conclusion_result.map_or(0.0, |res| res.time_real + self.executor.time_overhead()); 258 259 // Determine number of benchmark runs 260 let runs_in_min_time = (self.options.min_benchmarking_time 261 / (res.time_real 262 + self.executor.time_overhead() 263 + preparation_overhead 264 + conclusion_overhead)) as u64; 265 266 let count = { 267 let min = cmp::max(runs_in_min_time, self.options.run_bounds.min); 268 269 self.options 270 .run_bounds 271 .max 272 .as_ref() 273 .map(|max| cmp::min(min, *max)) 274 .unwrap_or(min) 275 }; 276 277 let count_remaining = count - 1; 278 279 // Save the first result 280 times_real.push(res.time_real); 281 times_user.push(res.time_user); 282 times_system.push(res.time_system); 283 memory_usage_byte.push(res.memory_usage_byte); 284 exit_codes.push(extract_exit_code(status)); 285 286 all_succeeded = all_succeeded && success; 287 288 // Re-configure the progress bar 289 if let Some(bar) = progress_bar.as_ref() { 290 bar.set_length(count) 291 } 292 if let Some(bar) = progress_bar.as_ref() { 293 bar.inc(1) 294 } 295 296 // Gather statistics (perform the actual benchmark) 297 for i in 0..count_remaining { 298 run_preparation_command()?; 299 300 let msg = { 301 let mean = format_duration(mean(×_real), self.options.time_unit); 302 format!("Current estimate: {}", mean.to_string().green()) 303 }; 304 305 if let Some(bar) = progress_bar.as_ref() { 306 bar.set_message(msg.to_owned()) 307 } 308 309 let (res, status) = self.executor.run_command_and_measure( 310 self.command, 311 BenchmarkIteration::Benchmark(i + 1), 312 None, 313 output_policy, 314 )?; 315 let success = status.success(); 316 317 times_real.push(res.time_real); 318 times_user.push(res.time_user); 319 times_system.push(res.time_system); 320 memory_usage_byte.push(res.memory_usage_byte); 321 exit_codes.push(extract_exit_code(status)); 322 323 all_succeeded = all_succeeded && success; 324 325 if let Some(bar) = progress_bar.as_ref() { 326 bar.inc(1) 327 } 328 329 run_conclusion_command()?; 330 } 331 332 if let Some(bar) = progress_bar.as_ref() { 333 bar.finish_and_clear() 334 } 335 336 // Compute statistical quantities 337 let t_num = times_real.len(); 338 let t_mean = mean(×_real); 339 let t_stddev = if times_real.len() > 1 { 340 Some(standard_deviation(×_real, Some(t_mean))) 341 } else { 342 None 343 }; 344 let t_median = median(×_real); 345 let t_min = min(×_real); 346 let t_max = max(×_real); 347 348 let user_mean = mean(×_user); 349 let system_mean = mean(×_system); 350 351 // Formatting and console output 352 let (mean_str, time_unit) = format_duration_unit(t_mean, self.options.time_unit); 353 let min_str = format_duration(t_min, Some(time_unit)); 354 let max_str = format_duration(t_max, Some(time_unit)); 355 let num_str = format!("{t_num} runs"); 356 357 let user_str = format_duration(user_mean, Some(time_unit)); 358 let system_str = format_duration(system_mean, Some(time_unit)); 359 360 if self.options.output_style != OutputStyleOption::Disabled { 361 if times_real.len() == 1 { 362 println!( 363 " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", 364 "abs".green().bold(), 365 mean_str.green().bold(), 366 " ", // alignment 367 user_str.blue(), 368 system_str.blue() 369 ); 370 } else { 371 let stddev_str = format_duration(t_stddev.unwrap(), Some(time_unit)); 372 373 println!( 374 " Time ({} ± {}): {:>8} ± {:>8} [User: {}, System: {}]", 375 "mean".green().bold(), 376 "σ".green(), 377 mean_str.green().bold(), 378 stddev_str.green(), 379 user_str.blue(), 380 system_str.blue() 381 ); 382 383 println!( 384 " Range ({} … {}): {:>8} … {:>8} {}", 385 "min".cyan(), 386 "max".purple(), 387 min_str.cyan(), 388 max_str.purple(), 389 num_str.dimmed() 390 ); 391 } 392 } 393 394 // Warnings 395 let mut warnings = vec![]; 396 397 // Check execution time 398 if matches!(self.options.executor_kind, ExecutorKind::Shell(_)) 399 && times_real.iter().any(|&t| t < MIN_EXECUTION_TIME) 400 { 401 warnings.push(Warnings::FastExecutionTime); 402 } 403 404 // Check program exit codes 405 if !all_succeeded { 406 warnings.push(Warnings::NonZeroExitCode); 407 } 408 409 // Run outlier detection 410 let scores = modified_zscores(×_real); 411 412 let outlier_warning_options = OutlierWarningOptions { 413 warmup_in_use: self.options.warmup_count > 0, 414 prepare_in_use: self 415 .options 416 .preparation_command 417 .as_ref() 418 .map(|v| v.len()) 419 .unwrap_or(0) 420 > 0, 421 }; 422 423 if scores[0] > OUTLIER_THRESHOLD { 424 warnings.push(Warnings::SlowInitialRun( 425 times_real[0], 426 outlier_warning_options, 427 )); 428 } else if scores.iter().any(|&s| s.abs() > OUTLIER_THRESHOLD) { 429 warnings.push(Warnings::OutliersDetected(outlier_warning_options)); 430 } 431 432 if !warnings.is_empty() { 433 eprintln!(" "); 434 435 for warning in &warnings { 436 eprintln!(" {}: {}", "Warning".yellow(), warning); 437 } 438 } 439 440 if self.options.output_style != OutputStyleOption::Disabled { 441 println!(" "); 442 } 443 444 self.run_cleanup_command(self.command.get_parameters().iter().cloned(), output_policy)?; 445 446 Ok(BenchmarkResult { 447 command: self.command.get_name(), 448 command_with_unused_parameters: self.command.get_name_with_unused_parameters(), 449 mean: t_mean, 450 stddev: t_stddev, 451 median: t_median, 452 user: user_mean, 453 system: system_mean, 454 min: t_min, 455 max: t_max, 456 times: Some(times_real), 457 memory_usage_byte: Some(memory_usage_byte), 458 exit_codes, 459 parameters: self 460 .command 461 .get_parameters() 462 .iter() 463 .map(|(name, value)| (name.to_string(), value.to_string())) 464 .collect(), 465 }) 466 } 467 }