From ae1ce7d3f6181cb4c37c4a4581aeb8e3a17517e0 Mon Sep 17 00:00:00 2001 From: leynos Date: Fri, 12 Jun 2026 20:32:53 +0200 Subject: [PATCH] Make verbose timing output sink injectable (#341) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `VerboseTimingReporter` bypassed the reporter abstraction by writing its timing summary lines straight to `io::stderr()`, creating a second hard-coded output path that tests and alternative reporters could not capture. Introduce an injectable `TimingSink` (one rendered line per call): `new` keeps the stderr default, while the new `with_sink` constructor lets callers route the summary anywhere. The accessible, silent, and indicatif reporter behaviour is unchanged — only the summary's destination becomes a policy of the constructor. Add a test that captures the summary through an injected sink without touching global stderr, alongside the existing behaviour tests. --- src/status_timing.rs | 43 ++++++++++++++++++++++++++++++-- src/status_timing_tests.rs | 51 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 92 insertions(+), 2 deletions(-) diff --git a/src/status_timing.rs b/src/status_timing.rs index 52cde1d4..7f35c4fd 100644 --- a/src/status_timing.rs +++ b/src/status_timing.rs @@ -9,6 +9,12 @@ use std::time::{Duration, Instant}; type MonotonicClock = dyn Fn() -> Duration + Send + Sync; +/// Destination for rendered timing summary lines. +/// +/// Injectable so tests and alternative reporters can capture the timing +/// output without relying on process-global stderr. +pub type TimingSink = dyn Fn(&str) + Send + Sync; + #[derive(Debug, Copy, Clone)] struct StageMarker { current: StageNumber, @@ -73,31 +79,64 @@ pub struct VerboseTimingReporter { inner: Box, prefs: OutputPrefs, clock: Box, + sink: Box, state: Mutex, } impl VerboseTimingReporter { /// Wrap an existing reporter with verbose timing summary support. + /// + /// Timing summary lines go to the process's stderr; use + /// [`VerboseTimingReporter::with_sink`] to capture them elsewhere. #[must_use] pub fn new(inner: Box, prefs: OutputPrefs) -> Self { + Self::with_sink(inner, prefs, Box::new(stderr_sink)) + } + + /// Wrap an existing reporter, sending timing summary lines to `sink`. + /// + /// The sink receives one rendered line per call, without a trailing + /// newline. + #[must_use] + pub fn with_sink( + inner: Box, + prefs: OutputPrefs, + sink: Box, + ) -> Self { let start = Instant::now(); - Self::with_clock(inner, prefs, Box::new(move || start.elapsed())) + Self::with_clock_and_sink(inner, prefs, Box::new(move || start.elapsed()), sink) } + #[cfg(test)] fn with_clock( inner: Box, prefs: OutputPrefs, clock: Box, + ) -> Self { + Self::with_clock_and_sink(inner, prefs, clock, Box::new(stderr_sink)) + } + + fn with_clock_and_sink( + inner: Box, + prefs: OutputPrefs, + clock: Box, + sink: Box, ) -> Self { Self { inner, prefs, clock, + sink, state: Mutex::new(TimingState::default()), } } } +/// Default timing sink: one line per call to the process's stderr. +fn stderr_sink(line: &str) { + drop(writeln!(io::stderr(), "{line}")); +} + impl StatusReporter for VerboseTimingReporter { fn report_stage(&self, current: StageNumber, total: StageNumber, description: &str) { let should_forward = { @@ -148,7 +187,7 @@ impl StatusReporter for VerboseTimingReporter { self.inner.report_complete(tool_key); for line in lines { - drop(writeln!(io::stderr(), "{line}")); + (self.sink)(&line); } } } diff --git a/src/status_timing_tests.rs b/src/status_timing_tests.rs index 4c0d0ac0..6faf9378 100644 --- a/src/status_timing_tests.rs +++ b/src/status_timing_tests.rs @@ -336,3 +336,54 @@ fn timing_summary_snapshot( Ok(()) } + +struct SilentInner; + +impl StatusReporter for SilentInner { + fn report_stage(&self, _current: StageNumber, _total: StageNumber, _description: &str) {} + fn report_complete(&self, _tool_key: LocalizationKey) {} +} + +#[rstest] +fn verbose_timing_reporter_routes_summary_through_injected_sink( + test_prefs: OutputPrefs, + en_us_localizer: Result, +) -> Result<()> { + let _localizer = en_us_localizer?; + let captured: Arc>> = Arc::new(Mutex::new(Vec::new())); + let sink_capture = Arc::clone(&captured); + let clock = Arc::new(FakeClock::from_millis(&[0, 15])); + let reporter_clock = Arc::clone(&clock); + let reporter = VerboseTimingReporter::with_clock_and_sink( + Box::new(SilentInner), + test_prefs, + Box::new(move || reporter_clock.now()), + Box::new(move |line| { + sink_capture + .lock() + .unwrap_or_else(std::sync::PoisonError::into_inner) + .push(line.to_owned()); + }), + ); + + reporter.report_stage( + StageNumber::new_unchecked(1), + StageNumber::new_unchecked(6), + "Reading manifest file", + ); + reporter.report_complete(LocalizationKey::new(keys::STATUS_TOOL_MANIFEST)); + + let lines = captured + .lock() + .unwrap_or_else(std::sync::PoisonError::into_inner) + .clone(); + let [header, stage_line, total_line] = lines.as_slice() else { + anyhow::bail!("expected 3 captured timing lines, got {lines:#?}"); + }; + anyhow::ensure!(normalize_fluent_isolates(header).contains("Stage timing summary:")); + anyhow::ensure!( + normalize_fluent_isolates(stage_line).contains("Stage 1/6: Reading manifest file") + ); + anyhow::ensure!(normalize_fluent_isolates(total_line).contains("Total pipeline time: 15ms")); + Ok(()) +}