diff --git a/src/benchmark/mod.rs b/src/benchmark/mod.rs index e3534a7..b6c615d 100644 --- a/src/benchmark/mod.rs +++ b/src/benchmark/mod.rs @@ -5,6 +5,7 @@ pub mod scheduler; pub mod timing_result; use std::cmp; +use std::io::{self, Write}; use crate::benchmark::executor::BenchmarkIteration; use crate::command::Command; @@ -12,6 +13,7 @@ use crate::options::{ CmdFailureAction, CommandOutputPolicy, ExecutorKind, Options, OutputStyleOption, }; use crate::outlier_detection::{modified_zscores, OUTLIER_THRESHOLD}; +use crate::output::console_writeln; use crate::output::format::{format_duration, format_duration_unit}; use crate::output::progress_bar::get_progress_bar; use crate::output::warnings::{OutlierWarningOptions, Warnings}; @@ -140,12 +142,13 @@ impl<'a> Benchmark<'a> { /// Run the benchmark for a single command pub fn run(&self) -> Result { if self.options.output_style != OutputStyleOption::Disabled { - println!( + console_writeln!( + io::stdout(), "{}{}: {}", "Benchmark ".bold(), (self.number + 1).to_string().bold(), self.command.get_name_with_unused_parameters(), - ); + )?; } let mut times_real: Vec = vec![]; @@ -358,19 +361,22 @@ impl<'a> Benchmark<'a> { let system_str = format_duration(system_mean, Some(time_unit)); if self.options.output_style != OutputStyleOption::Disabled { + let mut stdout = io::stdout().lock(); if times_real.len() == 1 { - println!( + console_writeln!( + stdout, " Time ({} ≡): {:>8} {:>8} [User: {}, System: {}]", "abs".green().bold(), mean_str.green().bold(), " ", // alignment user_str.blue(), system_str.blue() - ); + )?; } else { let stddev_str = format_duration(t_stddev.unwrap(), Some(time_unit)); - println!( + console_writeln!( + stdout, " Time ({} ± {}): {:>8} ± {:>8} [User: {}, System: {}]", "mean".green().bold(), "σ".green(), @@ -378,16 +384,17 @@ impl<'a> Benchmark<'a> { stddev_str.green(), user_str.blue(), system_str.blue() - ); + )?; - println!( + console_writeln!( + stdout, " Range ({} … {}): {:>8} … {:>8} {}", "min".cyan(), "max".purple(), min_str.cyan(), max_str.purple(), num_str.dimmed() - ); + )?; } } @@ -430,15 +437,16 @@ impl<'a> Benchmark<'a> { } if !warnings.is_empty() { - eprintln!(" "); + let mut stderr = io::stderr().lock(); + console_writeln!(stderr, " ")?; for warning in &warnings { - eprintln!(" {}: {}", "Warning".yellow(), warning); + console_writeln!(stderr, " {}: {}", "Warning".yellow(), warning)?; } } if self.options.output_style != OutputStyleOption::Disabled { - println!(" "); + console_writeln!(io::stdout(), " ")?; } self.run_cleanup_command(self.command.get_parameters().iter().cloned(), output_policy)?; diff --git a/src/benchmark/scheduler.rs b/src/benchmark/scheduler.rs index 69c19eb..ce5fd81 100644 --- a/src/benchmark/scheduler.rs +++ b/src/benchmark/scheduler.rs @@ -3,10 +3,12 @@ use super::executor::{Executor, MockExecutor, RawExecutor, ShellExecutor}; use super::{relative_speed, Benchmark}; use colored::*; use std::cmp::Ordering; +use std::io::{self, Write}; use crate::command::{Command, Commands}; use crate::export::ExportManager; use crate::options::{ExecutorKind, Options, OutputStyleOption, SortOrder}; +use crate::output::console_writeln; use anyhow::Result; @@ -58,13 +60,13 @@ impl<'a> Scheduler<'a> { Ok(()) } - pub fn print_relative_speed_comparison(&self) { + pub fn print_relative_speed_comparison(&self) -> Result<()> { if self.options.output_style == OutputStyleOption::Disabled { - return; + return Ok(()); } if self.results.len() < 2 { - return; + return Ok(()); } let reference = self @@ -79,17 +81,19 @@ impl<'a> Scheduler<'a> { reference, self.options.sort_order_speed_comparison, ) { + let mut stdout = io::stdout().lock(); match self.options.sort_order_speed_comparison { SortOrder::MeanTime => { - println!("{}", "Summary".bold()); + console_writeln!(stdout, "{}", "Summary".bold())?; let reference = annotated_results.iter().find(|r| r.is_reference).unwrap(); let others = annotated_results.iter().filter(|r| !r.is_reference); - println!( + console_writeln!( + stdout, " {} ran", reference.result.command_with_unused_parameters.cyan() - ); + )?; for item in others { let stddev = if let Some(stddev) = item.relative_speed_stddev { @@ -114,18 +118,20 @@ impl<'a> Scheduler<'a> { stddev ), }; - println!( + console_writeln!( + stdout, "{} {}", comparator, item.result.command_with_unused_parameters.magenta() - ); + )?; } } SortOrder::Command => { - println!("{}", "Relative speed comparison".bold()); + console_writeln!(stdout, "{}", "Relative speed comparison".bold())?; for item in annotated_results { - println!( + console_writeln!( + stdout, " {}{} {}", format!("{:10.2}", item.relative_speed).bold().green(), if item.is_reference { @@ -136,12 +142,13 @@ impl<'a> Scheduler<'a> { " ".into() }, item.result.command_with_unused_parameters, - ); + )?; } } } } else { - eprintln!( + console_writeln!( + io::stderr(), "{}: The benchmark comparison could not be computed as some benchmark times are zero. \ This could be caused by background interference during the initial calibration phase \ of hyperfine, in combination with very fast commands (faster than a few milliseconds). \ @@ -149,8 +156,10 @@ impl<'a> Scheduler<'a> { --shell=none/-N option. If it does not help either, you command is most likely too fast \ to be accurately benchmarked by hyperfine.", "Note".bold().red() - ); + )?; } + + Ok(()) } pub fn final_export(&self) -> Result<()> { diff --git a/src/error.rs b/src/error.rs index 53d39a5..9d1f482 100644 --- a/src/error.rs +++ b/src/error.rs @@ -3,6 +3,10 @@ use std::num::{self, ParseFloatError, ParseIntError}; use rust_decimal::Error as DecimalError; use thiserror::Error; +#[derive(Debug, Error)] +#[error(transparent)] +pub struct ConsoleOutputError(pub std::io::Error); + #[derive(Debug, Error)] pub enum ParameterScanError { #[error("Error while parsing parameter scan arguments ({0})")] diff --git a/src/export/mod.rs b/src/export/mod.rs index 3947a2e..e13c1d6 100644 --- a/src/export/mod.rs +++ b/src/export/mod.rs @@ -1,5 +1,5 @@ use std::fs::{File, OpenOptions}; -use std::io::Write; +use std::io::{self, Write}; mod asciidoc; mod csv; @@ -18,6 +18,7 @@ use self::orgmode::OrgmodeExporter; use crate::benchmark::benchmark_result::BenchmarkResult; use crate::options::SortOrder; +use crate::output::console_writeln; use crate::util::units::Unit; use anyhow::{Context, Result}; @@ -144,8 +145,9 @@ impl ExportManager { } ExportTarget::Stdout => { if !intermediate { - println!(); - println!("{}", String::from_utf8(content()?).unwrap()); + let mut stdout = io::stdout().lock(); + console_writeln!(stdout)?; + console_writeln!(stdout, "{}", String::from_utf8(content()?).unwrap())?; } } } diff --git a/src/main.rs b/src/main.rs index 2a97505..691e693 100644 --- a/src/main.rs +++ b/src/main.rs @@ -4,10 +4,12 @@ )] use std::env; +use std::io::{self, Write}; use benchmark::scheduler::Scheduler; use cli::get_cli_arguments; use command::Commands; +use error::ConsoleOutputError; use export::ExportManager; use options::Options; @@ -44,17 +46,29 @@ fn run() -> Result<()> { let mut scheduler = Scheduler::new(&commands, &options, &export_manager); scheduler.run_benchmarks()?; - scheduler.print_relative_speed_comparison(); + scheduler.print_relative_speed_comparison()?; scheduler.final_export()?; Ok(()) } +fn caused_by_broken_console_pipe(error: &anyhow::Error) -> bool { + error + .downcast_ref::() + .is_some_and(|e| e.0.kind() == io::ErrorKind::BrokenPipe) +} + fn main() { match run() { Ok(_) => {} Err(e) => { - eprintln!("{} {:#}", "Error:".red(), e); + // Exit quietly when a reader stops consuming console output early. + if caused_by_broken_console_pipe(&e) { + std::process::exit(0); + } + // The write to stderr can itself fail if stderr is closed; the + // error message cannot be shown in that case anyway. + let _ = writeln!(io::stderr(), "{} {:#}", "Error:".red(), e); std::process::exit(1); } } diff --git a/src/output/mod.rs b/src/output/mod.rs index d80ffee..aa2f85b 100644 --- a/src/output/mod.rs +++ b/src/output/mod.rs @@ -1,3 +1,13 @@ pub mod format; pub mod progress_bar; pub mod warnings; + +/// Mark console write errors so broken pipes can be handled separately from file errors. +macro_rules! console_writeln { + ($writer:expr $(, $($args:tt)*)?) => { + writeln!($writer $(, $($args)*)?) + .map_err($crate::error::ConsoleOutputError) + }; +} + +pub(crate) use console_writeln; diff --git a/tests/integration_tests.rs b/tests/integration_tests.rs index 2de3a50..54e3844 100644 --- a/tests/integration_tests.rs +++ b/tests/integration_tests.rs @@ -1,5 +1,5 @@ mod common; -use common::hyperfine; +use common::{hyperfine, hyperfine_raw_command}; use predicates::prelude::*; @@ -33,6 +33,47 @@ fn one_run_is_supported() { .success(); } +/// Regression test: hyperfine must not panic when writing to a closed +/// stdout pipe (e.g. `hyperfine ... | head -n 1` or a downstream process +/// that terminates early). A `BrokenPipe` error should result in a quiet +/// exit with code 0 instead of a `println!` panic. +#[test] +fn exits_quietly_when_stdout_is_closed() { + use std::process::Stdio; + + for args in [ + vec!["--runs=1", "echo dummy benchmark"], + vec!["--runs=1", "--export-json=-", "echo dummy benchmark"], + vec!["--runs=1", "echo dummy benchmark", "echo second benchmark"], + ] { + // A pipe whose read end has been closed before hyperfine is even + // started: every write to it will fail with `BrokenPipe`. + let (reader, writer) = std::io::pipe().expect("failed to create pipe"); + drop(reader); + + let output = hyperfine_raw_command() + .args(&args) + .stdout(writer) + .stderr(Stdio::piped()) + .spawn() + .expect("failed to spawn hyperfine") + .wait_with_output() + .expect("failed to wait for hyperfine"); + let stderr = String::from_utf8_lossy(&output.stderr); + + assert!( + !stderr.contains("panicked"), + "hyperfine panicked while writing to a closed pipe:\n{}", + stderr + ); + assert!( + output.status.success(), + "hyperfine did not exit cleanly; stderr:\n{}", + stderr + ); + } +} + #[test] fn can_run_commands_without_a_shell() { hyperfine()