fix: do not write console logs over the interactive TUI

src/commands/tui.rs

@@ -15,6 +15,7 @@ pub use snapshots::Snapshots;
 use std::io;
 use std::sync::{Arc, RwLock};
 
+use crate::config::logging::TuiLogCapture;
 use anyhow::Result;
 use crossterm::event::{KeyEvent, KeyModifiers};
 use crossterm::{
@@ -38,18 +39,26 @@ impl TuiResult for bool {
 }
 
 pub fn run(f: impl FnOnce(TuiProgressBars) -> Result<()>) -> Result<()> {
-    // setup terminal
+    // Keep console logs off the TUI; flush them after the terminal is restored.
+    let log_capture = TuiLogCapture::start();
+
     let terminal = init_terminal()?;
     let terminal = Arc::new(RwLock::new(terminal));
 
-    // restore terminal (even when leaving through ?, early return, or panic)
-    defer! {
-        reset_terminal().unwrap();
-    }
+    let result = {
+        // restore terminal (even when leaving through ?, early return, or panic)
+        defer! {
+            reset_terminal().unwrap();
+        }
+
+        let progress = TuiProgressBars { terminal };
+        f(progress)
+    };
 
-    let progress = TuiProgressBars { terminal };
+    // Terminal is back to cooked mode; now replay captured logs and errors.
+    drop(log_capture);
 
-    if let Err(err) = f(progress) {
+    if let Err(err) = result {
         println!("{err:?}");
     }
 

src/config/logging.rs

@@ -1,4 +1,7 @@
-use std::{path::PathBuf, sync::OnceLock};
+use std::collections::VecDeque;
+use std::io::Write;
+use std::path::PathBuf;
+use std::sync::{Mutex, MutexGuard, OnceLock, PoisonError};
 
 use anyhow::Result;
 use clap::{Parser, ValueHint};
@@ -19,6 +22,103 @@ use serde_with::{DisplayFromStr, serde_as};
 
 use crate::config::progress_options::multi_progress;
 
+/// Maximum console log records held while the TUI owns the terminal.
+const MAX_CAPTURED_CONSOLE_LOGS: usize = 256;
+
+struct ConsoleCaptureState {
+    /// Number of live [`TuiLogCapture`] guards.
+    depth: usize,
+    records: VecDeque<String>,
+    dropped: usize,
+}
+
+static CONSOLE_CAPTURE: Mutex<ConsoleCaptureState> = Mutex::new(ConsoleCaptureState {
+    depth: 0,
+    records: VecDeque::new(),
+    dropped: 0,
+});
+
+fn console_capture() -> MutexGuard<'static, ConsoleCaptureState> {
+    CONSOLE_CAPTURE
+        .lock()
+        .unwrap_or_else(PoisonError::into_inner)
+}
+
+/// Divert console log output away from the terminal while the TUI is active.
+///
+/// File logging is unaffected. When the last guard is dropped, captured messages
+/// are printed to stderr (after the TUI should have restored the terminal).
+#[derive(Debug)]
+pub struct TuiLogCapture {
+    _private: (),
+}
+
+impl TuiLogCapture {
+    /// Start capturing console logs until this guard is dropped.
+    #[must_use = "console logs are only captured while this guard is alive"]
+    pub fn start() -> Self {
+        let mut state = console_capture();
+        if state.depth == 0 {
+            state.records.clear();
+            state.dropped = 0;
+        }
+        state.depth = state.depth.saturating_add(1);
+        drop(state);
+        Self { _private: () }
+    }
+}
+
+impl Drop for TuiLogCapture {
+    fn drop(&mut self) {
+        let captured = {
+            let mut state = console_capture();
+            state.depth = state.depth.saturating_sub(1);
+            if state.depth == 0 {
+                Some((
+                    std::mem::take(&mut state.records),
+                    std::mem::take(&mut state.dropped),
+                ))
+            } else {
+                None
+            }
+        };
+
+        if let Some((records, dropped)) = captured {
+            write_captured_console_logs(std::io::stderr(), records, dropped);
+        }
+    }
+}
+
+fn write_captured_console_logs(mut writer: impl Write, records: VecDeque<String>, dropped: usize) {
+    if dropped > 0 {
+        _ = writeln!(writer, "[{dropped} older log messages omitted]");
+    }
+    for record in records {
+        _ = writeln!(writer, "{record}");
+    }
+}
+
+/// Capture `record` when a TUI session owns the terminal.
+///
+/// Returns `true` if the record was captured and must not be written to the
+/// console (which would overwrite the TUI).
+fn capture_console_log(record: &log::Record<'_>) -> bool {
+    let mut state = console_capture();
+    if state.depth == 0 {
+        return false;
+    }
+
+    if state.records.len() >= MAX_CAPTURED_CONSOLE_LOGS {
+        _ = state.records.pop_front();
+        state.dropped = state.dropped.saturating_add(1);
+    }
+    state
+        .records
+        .push_back(format!("[{}] {}", record.level(), record.args()));
+    drop(state);
+    true
+}
+
 /// Logging Config
 #[serde_as]
 #[derive(Default, Debug, Parser, Clone, Deserialize, Serialize, Merge)]
@@ -123,12 +223,19 @@ impl LoggingOptions {
     }
 }
 
-/// A wrapper around [`ConsoleAppender`] that suspends the progress bar when writing logs.
+/// Console appender that coordinates with progress bars and the TUI.
+///
+/// While a [`TuiLogCapture`] guard is active, records are buffered instead of
+/// being written to the terminal. Otherwise the indicatif progress bar is
+/// suspended for the duration of the write.
 #[derive(Debug)]
 struct PbPauseAppender(ConsoleAppender);
 
 impl log4rs::append::Append for PbPauseAppender {
     fn append(&self, record: &log::Record<'_>) -> Result<()> {
+        if capture_console_log(record) {
+            return Ok(());
+        }
         multi_progress().suspend(|| self.0.append(record))
     }
 
@@ -141,3 +248,141 @@ impl log4rs::append::Append for PbPauseAppender {
         self.0.flush();
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use std::sync::Mutex;
+
+    static TEST_LOCK: Mutex<()> = Mutex::new(());
+
+    fn lock_tests() -> MutexGuard<'static, ()> {
+        TEST_LOCK.lock().unwrap_or_else(PoisonError::into_inner)
+    }
+
+    fn reset_capture() {
+        let mut state = console_capture();
+        state.depth = 0;
+        state.records.clear();
+        state.dropped = 0;
+    }
+
+    fn capture_warn(msg: &str) -> bool {
+        capture_console_log(
+            &log::Record::builder()
+                .args(format_args!("{msg}"))
+                .level(log::Level::Warn)
+                .target("test")
+                .build(),
+        )
+    }
+
+    fn snapshot() -> (usize, Vec<String>, usize) {
+        let state = console_capture();
+        (
+            state.depth,
+            state.records.iter().cloned().collect(),
+            state.dropped,
+        )
+    }
+
+    fn drain_capture() {
+        let mut state = console_capture();
+        state.records.clear();
+        state.dropped = 0;
+    }
+
+    #[test]
+    fn console_logs_pass_through_without_tui_capture() {
+        let _lock = lock_tests();
+        reset_capture();
+        assert!(!capture_warn("will retry Read"));
+        assert_eq!(snapshot(), (0, Vec::new(), 0));
+    }
+
+    #[test]
+    fn tui_capture_holds_console_logs_until_drop() {
+        let _lock = lock_tests();
+        reset_capture();
+
+        let capture = TuiLogCapture::start();
+        assert!(capture_warn("will retry Read (attempt 1)"));
+        assert!(capture_warn("still reading index"));
+        assert_eq!(
+            snapshot(),
+            (
+                1,
+                vec![
+                    "[WARN] will retry Read (attempt 1)".to_string(),
+                    "[WARN] still reading index".to_string(),
+                ],
+                0
+            )
+        );
+
+        drain_capture();
+        drop(capture);
+        assert_eq!(snapshot(), (0, Vec::new(), 0));
+        assert!(!capture_warn("after tui"));
+    }
+
+    #[test]
+    fn nested_tui_capture_flushes_on_outermost_drop() {
+        let _lock = lock_tests();
+        reset_capture();
+
+        let outer = TuiLogCapture::start();
+        assert!(capture_warn("outer"));
+        {
+            let inner = TuiLogCapture::start();
+            assert!(capture_warn("inner"));
+            drop(inner);
+            assert_eq!(
+                snapshot(),
+                (
+                    1,
+                    vec!["[WARN] outer".to_string(), "[WARN] inner".to_string()],
+                    0
+                )
+            );
+        }
+
+        drain_capture();
+        drop(outer);
+        assert_eq!(snapshot(), (0, Vec::new(), 0));
+    }
+
+    #[test]
+    fn tui_capture_drops_oldest_records_when_full() {
+        let _lock = lock_tests();
+        reset_capture();
+
+        let capture = TuiLogCapture::start();
+        for i in 0..=MAX_CAPTURED_CONSOLE_LOGS {
+            assert!(capture_warn(&format!("msg {i}")));
+        }
+
+        let (depth, records, dropped) = snapshot();
+        assert_eq!(depth, 1);
+        assert_eq!(dropped, 1);
+        assert_eq!(records.len(), MAX_CAPTURED_CONSOLE_LOGS);
+        assert_eq!(records[0], "[WARN] msg 1");
+        assert_eq!(
+            records[MAX_CAPTURED_CONSOLE_LOGS - 1],
+            format!("[WARN] msg {MAX_CAPTURED_CONSOLE_LOGS}")
+        );
+
+        drain_capture();
+        drop(capture);
+    }
+
+    #[test]
+    fn captured_logs_replay_with_omission_notice() {
+        let mut out = Vec::new();
+        write_captured_console_logs(&mut out, VecDeque::from(["[WARN] retry".to_string()]), 2);
+        assert_eq!(
+            String::from_utf8(out).unwrap(),
+            "[2 older log messages omitted]\n[WARN] retry\n"
+        );
+    }
+}