From aa9b05a55219f6e73ac5dcff0711d56d98647568 Mon Sep 17 00:00:00 2001 From: Bryan Helmkamp Date: Mon, 23 Feb 2026 18:16:12 -0500 Subject: [PATCH] Add timing output to default (non-verbose) pipeline runs Show per-stage completion/failure timing and total pipeline duration in the result block, even without -v flag. Uses a new format_duration_human helper for human-readable durations (ms/s/m s). Co-Authored-By: Claude Opus 4.6 --- crates/attractor/src/cli/mod.rs | 20 ++++++++++++++++++++ crates/attractor/src/cli/run.rs | 25 ++++++++++++++++++++++++- 2 files changed, 44 insertions(+), 1 deletion(-) diff --git a/crates/attractor/src/cli/mod.rs b/crates/attractor/src/cli/mod.rs index 9acecfca5..51894249e 100644 --- a/crates/attractor/src/cli/mod.rs +++ b/crates/attractor/src/cli/mod.rs @@ -141,6 +141,26 @@ pub fn print_diagnostics(diagnostics: &[Diagnostic], styles: &Styles) { } } +/// Format milliseconds into a human-readable duration string. +/// +/// - < 1000ms: `123ms` +/// - < 60s: `12.3s` +/// - >= 60s: `1m 23s` +#[must_use] +pub fn format_duration_human(ms: u64) -> String { + if ms < 1000 { + format!("{ms}ms") + } else if ms < 60_000 { + let secs = ms as f64 / 1000.0; + format!("{secs:.1}s") + } else { + let total_secs = ms / 1000; + let minutes = total_secs / 60; + let secs = total_secs % 60; + format!("{minutes}m {secs}s") + } +} + /// One-line summary of a pipeline event for `-v` output (dimmed). #[must_use] pub fn format_event_summary(event: &PipelineEvent, styles: &Styles) -> String { diff --git a/crates/attractor/src/cli/run.rs b/crates/attractor/src/cli/run.rs index c07b44fb5..c80a47ed2 100644 --- a/crates/attractor/src/cli/run.rs +++ b/crates/attractor/src/cli/run.rs @@ -1,5 +1,6 @@ use std::path::PathBuf; use std::sync::Arc; +use std::time::Instant; use anyhow::bail; use chrono::Local; @@ -17,7 +18,7 @@ use crate::pipeline::PipelineBuilder; use crate::validation::Severity; use super::backend::AgentBackend; -use super::{format_event_detail, format_event_summary, print_diagnostics, read_dot_file, RunArgs}; +use super::{format_duration_human, format_event_detail, format_event_summary, print_diagnostics, read_dot_file, RunArgs}; /// Execute a full pipeline run. /// @@ -76,6 +77,25 @@ pub async fn run_command(args: RunArgs, styles: &'static Styles) -> anyhow::Resu emitter.on_event(move |event| { eprintln!("{}", format_event_summary(event, styles)); }); + } else { + emitter.on_event(move |event| { + match event { + crate::event::PipelineEvent::StageCompleted { name, duration_ms, status, .. } => { + eprintln!( + "{dim}Stage \"{name}\" completed ({status}) in {duration}{reset}", + duration = format_duration_human(*duration_ms), + dim = styles.dim, reset = styles.reset, + ); + } + crate::event::PipelineEvent::StageFailed { name, .. } => { + eprintln!( + "{dim}Stage \"{name}\" failed{reset}", + dim = styles.dim, reset = styles.reset, + ); + } + _ => {} + } + }); } // 4. Build interviewer @@ -153,6 +173,7 @@ pub async fn run_command(args: RunArgs, styles: &'static Styles) -> anyhow::Resu cancel_token: None, }; + let run_start = Instant::now(); let outcome = if let Some(ref checkpoint_path) = args.resume { let checkpoint = Checkpoint::load(checkpoint_path)?; engine @@ -161,6 +182,7 @@ pub async fn run_command(args: RunArgs, styles: &'static Styles) -> anyhow::Resu } else { engine.run(&graph, &config).await? }; + let run_duration_ms = run_start.elapsed().as_millis() as u64; // 8. Print result eprintln!( @@ -174,6 +196,7 @@ pub async fn run_command(args: RunArgs, styles: &'static Styles) -> anyhow::Resu _ => styles.red, }; eprintln!("Status: {status_color}{status_str}{reset}", reset = styles.reset); + eprintln!("Duration: {}", format_duration_human(run_duration_ms)); if let Some(notes) = &outcome.notes { eprintln!("Notes: {notes}");