run: add --details options

Closes: #58

Author: sylvestre

crates/cargo-codspeed/README.md

@@ -48,6 +48,26 @@ Options:
   -V, --version  Print version information
 ```
 
+### Running benchmarks with details
+
+Use the `--details` flag to see timing information for each benchmark:
+
+```bash
+cargo codspeed run --details
+```
+
+This will show execution times for each benchmark:
+```
+  Checked: benches/example.rs::fibonacci (5.6 us)
+  Checked: benches/example.rs::factorial (368 ns)
+```
+
+The output also shows the total number of benchmarks executed:
+```
+Done running benchmark_suite (5 benchmarks)
+Finished running 2 benchmark suite(s) (10 benchmarks total)
+```
+
 ## Development
 
 ### Troubleshooting

crates/cargo-codspeed/src/app.rs

@@ -85,6 +85,10 @@ enum Commands {
 
         #[command(flatten)]
         bench_target_filters: BenchTargetFilters,
+
+        /// Print per-benchmark duration details
+        #[arg(long)]
+        details: bool,
     },
 }
 
@@ -141,12 +145,14 @@ pub fn run(args: impl Iterator<Item = OsString>) -> Result<()> {
             benchname,
             package_filters,
             bench_target_filters,
+            details,
         } => run_benches(
             &metadata,
             benchname,
             package_filters,
             bench_target_filters,
             measurement_mode,
+            details,
         ),
     };
 

crates/cargo-codspeed/src/run.rs

@@ -10,6 +10,7 @@ use codspeed::walltime_results::WalltimeResults;
 use std::{
     io::{self, Write},
     path::{Path, PathBuf},
+    process::Stdio,
 };
 
 #[cfg(unix)]
@@ -99,6 +100,7 @@ pub fn run_benches(
     package_filters: PackageFilters,
     bench_target_filters: BenchTargetFilters,
     measurement_mode: MeasurementMode,
+    show_details: bool,
 ) -> Result<()> {
     let codspeed_target_dir = get_codspeed_target_dir(metadata, measurement_mode);
     let workspace_root = metadata.workspace_root.as_std_path();
@@ -113,16 +115,29 @@ pub fn run_benches(
 
     eprintln!("Collected {} benchmark suite(s) to run", benches.len());
 
+    let mut total_benchmark_count = 0;
+
     for bench in benches.iter() {
         let bench_target_name = &bench.bench_target_name;
         // workspace_root is needed since file! returns the path relatively to the workspace root
         // while CARGO_MANIFEST_DIR returns the path to the sub package
         let workspace_root = metadata.workspace_root.clone();
-        eprintln!("Running {} {}", &bench.package_name, bench_target_name);
+        eprintln!(
+            "Running {} {} ({})",
+            &bench.package_name,
+            bench_target_name,
+            bench.bench_path.display()
+        );
         let mut command = std::process::Command::new(&bench.bench_path);
         command
             .env("CODSPEED_CARGO_WORKSPACE_ROOT", workspace_root)
-            .current_dir(&bench.working_directory);
+            .current_dir(&bench.working_directory)
+            .stdout(Stdio::piped())
+            .stderr(Stdio::inherit());
+
+        if show_details {
+            command.env("CODSPEED_SHOW_DETAILS", "1");
+        }
 
         if measurement_mode == MeasurementMode::Walltime {
             command.arg("--bench"); // Walltime targets need this additional argument (inherited from running them with `cargo bench`)
@@ -132,33 +147,63 @@ pub fn run_benches(
             command.arg(bench_name_filter);
         }
 
-        command
-            .status()
-            .map_err(|e| anyhow!("failed to execute the benchmark process: {}", e))
-            .and_then(|status| {
-                if status.success() {
-                    Ok(())
-                } else {
-                    #[cfg(unix)]
-                    {
-                        let code = status
-                            .code()
-                            .or(status.signal().map(|s| 128 + s)) // 128+N indicates that a command was interrupted by signal N (see: https://tldp.org/LDP/abs/html/exitcodes.html)
-                            .unwrap_or(1);
-
-                        eprintln!("failed to execute the benchmark process, exit code: {code}");
-
-                        std::process::exit(code);
-                    }
-                    #[cfg(not(unix))]
-                    {
-                        bail!("failed to execute the benchmark process: {}", status)
-                    }
-                }
-            })?;
-        eprintln!("Done running {bench_target_name}");
+        let output = command
+            .output()
+            .map_err(|e| anyhow!("failed to execute the benchmark process: {}", e))?;
+
+        // Count benchmarks by looking for "Measured:" or "Checked:" lines
+        let stdout = String::from_utf8_lossy(&output.stdout);
+        let benchmark_count = stdout
+            .lines()
+            .filter(|line| {
+                line.trim_start().starts_with("Measured:")
+                    || line.trim_start().starts_with("Checked:")
+                    || (show_details && line.trim_start().starts_with("  Checked:"))
+                    || (show_details && line.trim_start().starts_with("  Measured:"))
+            })
+            .count();
+        total_benchmark_count += benchmark_count;
+
+        // Print captured output
+        print!("{stdout}");
+        io::stdout().flush().unwrap();
+
+        if !output.status.success() {
+            #[cfg(unix)]
+            {
+                let code = output
+                    .status
+                    .code()
+                    .or(output.status.signal().map(|s| 128 + s)) // 128+N indicates that a command was interrupted by signal N (see: https://tldp.org/LDP/abs/html/exitcodes.html)
+                    .unwrap_or(1);
+
+                eprintln!("failed to execute the benchmark process, exit code: {code}");
+
+                std::process::exit(code);
+            }
+            #[cfg(not(unix))]
+            {
+                bail!("failed to execute the benchmark process: {}", output.status)
+            }
+        }
+
+        if benchmark_count == 0 && !stdout.is_empty() {
+            eprintln!("Warning: No benchmarks detected in output for {bench_target_name}");
+        }
+        if show_details {
+            eprintln!("Done running {bench_target_name} ({benchmark_count} benchmarks)");
+        } else {
+            eprintln!("Done running {bench_target_name}");
+        }
+    }
+    if show_details {
+        eprintln!(
+            "Finished running {} benchmark suite(s) ({total_benchmark_count} benchmarks total)",
+            benches.len()
+        );
+    } else {
+        eprintln!("Finished running {} benchmark suite(s)", benches.len());
     }
-    eprintln!("Finished running {} benchmark suite(s)", benches.len());
 
     if measurement_mode == MeasurementMode::Walltime {
         aggregate_raw_walltime_data(workspace_root)?;

crates/codspeed/src/codspeed.rs

@@ -1,6 +1,7 @@
-use crate::measurement;
+use crate::{measurement, utils};
 use colored::Colorize;
 use std::ffi::CString;
+use std::time::{Duration, Instant};
 
 pub use std::hint::black_box;
 
@@ -15,11 +16,14 @@ pub struct CodSpeed {
     current_benchmark: CString,
     group_stack: Vec<String>,
     is_instrumented: bool,
+    start_time: Option<Instant>,
+    show_details: bool,
 }
 
 impl CodSpeed {
     pub fn new() -> Self {
         let is_instrumented = measurement::is_instrumented();
+        let show_details = utils::show_details();
         if !is_instrumented {
             println!(
                 "{} codspeed is enabled, but no performance measurement will be made since it's running in an unknown environment.",
@@ -32,6 +36,8 @@ impl CodSpeed {
             current_benchmark: CString::new("").expect("CString::new failed"),
             group_stack: Vec::new(),
             is_instrumented,
+            start_time: None,
+            show_details,
         }
     }
 
@@ -47,29 +53,56 @@ impl CodSpeed {
     pub fn start_benchmark(&mut self, name: &str) {
         self.current_benchmark = CString::new(name).expect("CString::new failed");
         measurement::start();
+        if self.show_details && !self.is_instrumented {
+            self.start_time = Some(Instant::now());
+        } else {
+            self.start_time = None;
+        }
     }
 
     #[inline(always)]
     pub fn end_benchmark(&mut self) {
         measurement::stop(&self.current_benchmark);
         self.benchmarked
             .push(self.current_benchmark.to_str().unwrap().to_string());
-        let action_str = if self.is_instrumented {
-            "Measured"
-        } else {
-            "Checked"
-        };
-        let group_str = if self.group_stack.is_empty() {
-            "".to_string()
+        if self.show_details {
+            if !self.is_instrumented {
+                let elapsed = self
+                    .start_time
+                    .take()
+                    .map(|start| start.elapsed())
+                    .unwrap_or_default();
+                let group_str = if self.group_stack.is_empty() {
+                    "".to_string()
+                } else {
+                    format!(" (group: {})", self.group_stack.join("/"))
+                };
+                let formatted_duration = format_duration(elapsed);
+                println!(
+                    "  Checked: {}{} ({})",
+                    self.current_benchmark.to_string_lossy(),
+                    group_str,
+                    formatted_duration
+                );
+            }
         } else {
-            format!(" (group: {})", self.group_stack.join("/"))
-        };
-        println!(
-            "{}: {}{}",
-            action_str,
-            self.current_benchmark.to_string_lossy(),
-            group_str
-        );
+            let action_str = if self.is_instrumented {
+                "Measured"
+            } else {
+                "Checked"
+            };
+            let group_str = if self.group_stack.is_empty() {
+                "".to_string()
+            } else {
+                format!(" (group: {})", self.group_stack.join("/"))
+            };
+            println!(
+                "{}: {}{}",
+                action_str,
+                self.current_benchmark.to_string_lossy(),
+                group_str
+            );
+        }
     }
 }
 
@@ -78,3 +111,45 @@ impl Default for CodSpeed {
         Self::new()
     }
 }
+
+fn format_duration(duration: Duration) -> String {
+    let nanos = duration.as_nanos();
+    if nanos == 0 {
+        return "<1 ns".to_string();
+    }
+
+    if nanos < 1_000 {
+        format!("{nanos} ns")
+    } else if nanos < 1_000_000 {
+        format!("{:.1} us", nanos as f64 / 1_000.0)
+    } else if nanos < 1_000_000_000 {
+        format!("{:.1} ms", nanos as f64 / 1_000_000.0)
+    } else {
+        format!("{:.2} s", nanos as f64 / 1_000_000_000.0)
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn format_duration_handles_zero() {
+        assert_eq!(format_duration(Duration::from_nanos(0)), "<1 ns");
+    }
+
+    #[test]
+    fn format_duration_scales_to_microseconds() {
+        assert_eq!(format_duration(Duration::from_nanos(1_500)), "1.5 us");
+    }
+
+    #[test]
+    fn format_duration_scales_to_milliseconds() {
+        assert_eq!(format_duration(Duration::from_micros(2_345)), "2.3 ms");
+    }
+
+    #[test]
+    fn format_duration_scales_to_seconds() {
+        assert_eq!(format_duration(Duration::from_millis(2_500)), "2.50 s");
+    }
+}

crates/codspeed/src/utils.rs

@@ -46,6 +46,10 @@ pub fn is_perf_enabled() -> bool {
     std::env::var("CODSPEED_PERF_ENABLED").is_ok()
 }
 
+pub fn show_details() -> bool {
+    std::env::var("CODSPEED_SHOW_DETAILS").is_ok()
+}
+
 #[cfg(test)]
 mod tests {
     use super::*;