Skip to main content

gam_solve/
progress_log.rs

1//! Stderr progress logger for the `gam` CLI and the `gamfit` Python bindings.
2//!
3//! Installs a global [`log`] backend that timestamps each record (elapsed since
4//! process start), strips terminal control / escape sequences, and writes to
5//! stderr under a write-lock so concurrent solver threads never interleave
6//! partial lines. This is the sole logger bootstrap for the CLI binary and the
7//! Python extension module.
8//!
9//! (Extracted from the former TUI `visualizer` module, which has been removed
10//! along with its `crossterm`/`ratatui` dependencies; only the stderr logging
11//! survives — the live chart / progress lanes were non-essential opt-in cruft.)
12
13use log::{LevelFilter, Log, Metadata, Record};
14use std::io::{self, Write};
15use std::sync::{Mutex, OnceLock};
16use std::time::{Duration, Instant};
17
18static LOGGER: ProgressLogger = ProgressLogger;
19static LOG_START: OnceLock<Instant> = OnceLock::new();
20static LOG_WRITE_LOCK: Mutex<()> = Mutex::new(());
21
22struct ProgressLogger;
23
24impl Log for ProgressLogger {
25    fn enabled(&self, metadata: &Metadata<'_>) -> bool {
26        metadata.level() <= log::max_level()
27    }
28
29    fn log(&self, record: &Record<'_>) {
30        if !self.enabled(record.metadata()) {
31            return;
32        }
33        let lines = format_log_record(record);
34        let log_lock_guard = LOG_WRITE_LOCK.lock().unwrap_or_else(|p| p.into_inner());
35        let mut stderr = io::stderr().lock();
36        for line in lines {
37            writeln!(stderr, "{line}").ok();
38        }
39        drop(log_lock_guard);
40    }
41
42    fn flush(&self) {}
43}
44
45fn format_log_record(record: &Record<'_>) -> Vec<String> {
46    let elapsed = LOG_START.get_or_init(Instant::now).elapsed();
47    let prefix = format!("[{}]", human_elapsed(elapsed));
48    sanitize_log_message(&record.args().to_string())
49        .lines()
50        .map(|line| format!("{prefix} {line}"))
51        .collect()
52}
53
54fn sanitize_log_message(message: &str) -> String {
55    let mut sanitized = String::with_capacity(message.len());
56    let mut chars = message.chars().peekable();
57    while let Some(ch) = chars.next() {
58        match ch {
59            '\x1b' => {
60                strip_escape_sequence(&mut chars);
61            }
62            '\r' => sanitized.push('\n'),
63            '\n' | '\t' => sanitized.push(ch),
64            ch if ch.is_control() => {}
65            ch => sanitized.push(ch),
66        }
67    }
68    sanitized
69}
70
71fn strip_escape_sequence<I>(chars: &mut std::iter::Peekable<I>)
72where
73    I: Iterator<Item = char>,
74{
75    match chars.next() {
76        Some('[') => {
77            for seq_ch in chars.by_ref() {
78                if ('@'..='~').contains(&seq_ch) {
79                    break;
80                }
81            }
82        }
83        Some(']') => strip_string_escape(chars),
84        Some('P' | 'X' | '^' | '_') => strip_string_escape(chars),
85        Some(_) | None => {}
86    }
87}
88
89fn strip_string_escape<I>(chars: &mut std::iter::Peekable<I>)
90where
91    I: Iterator<Item = char>,
92{
93    while let Some(seq_ch) = chars.next() {
94        if seq_ch == '\x07' {
95            break;
96        }
97        if seq_ch == '\x1b' && chars.next_if_eq(&'\\').is_some() {
98            break;
99        }
100    }
101}
102
103fn human_elapsed(elapsed: Duration) -> String {
104    let total_secs = elapsed.as_secs();
105    let hours = total_secs / 3600;
106    let minutes = (total_secs / 60) % 60;
107    let seconds = total_secs % 60;
108    if hours > 0 {
109        format!("{hours}h {minutes:02}m {seconds:02}s")
110    } else if minutes > 0 {
111        format!("{minutes}m {seconds:02}s")
112    } else {
113        format!("{seconds}s")
114    }
115}
116
117pub fn init_logging() {
118    LOG_START.get_or_init(Instant::now);
119    if log::set_logger(&LOGGER).is_ok() {
120        log::set_max_level(LevelFilter::Info);
121    }
122    // Log the GPU backend inventory once at startup so the "are GPUs being
123    // used?" answer is visible at the top of the log, before any solver
124    // dispatch site lazily checks for device support.
125    gam_gpu::log_backend_inventory_once();
126}