Make verbose timing output sink injectable (#341)

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<dyn StatusReporter>,
     prefs: OutputPrefs,
     clock: Box<MonotonicClock>,
+    sink: Box<TimingSink>,
     state: Mutex<TimingState>,
 }
 
 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<dyn StatusReporter>, 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<dyn StatusReporter>,
+        prefs: OutputPrefs,
+        sink: Box<TimingSink>,
+    ) -> 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<dyn StatusReporter>,
         prefs: OutputPrefs,
         clock: Box<MonotonicClock>,
+    ) -> Self {
+        Self::with_clock_and_sink(inner, prefs, clock, Box::new(stderr_sink))
+    }
+
+    fn with_clock_and_sink(
+        inner: Box<dyn StatusReporter>,
+        prefs: OutputPrefs,
+        clock: Box<MonotonicClock>,
+        sink: Box<TimingSink>,
     ) -> 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);
         }
     }
 }

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<EnUsLocalizerFixture>,
+) -> Result<()> {
+    let _localizer = en_us_localizer?;
+    let captured: Arc<Mutex<Vec<String>>> = 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(())
+}