ferroui_inspect/
logs.rs

1//! One bounded diagnostic capture per process, shared by every inspection server (MCP, CDP). The
2//! first [`LogCapture::install`] tees the framework's log sink; the tee forwards to the sink it
3//! replaced, and that sink is restored when the last [`LogGuard`] is dropped.
4use ferroui_base::logging::{ILogSink, LogEventLevel, Logger};
5use serde_json::{json, Value};
6use std::{
7    any::Any,
8    collections::VecDeque,
9    fmt::Display,
10    sync::{
11        atomic::{AtomicI32, Ordering},
12        Arc, Mutex,
13    },
14    time::{SystemTime, UNIX_EPOCH},
15};
16
17const CAPACITY: usize = 1024;
18const DEFAULT_MINIMUM: LogEventLevel = LogEventLevel::Information;
19
20/// A captured log event. The template keeps its placeholders; the values are kept apart.
21#[derive(Clone, Debug)]
22pub struct LogEntry {
23    pub sequence: u64,
24    pub level: LogEventLevel,
25    pub area: String,
26    pub template: String,
27    pub values: Vec<String>,
28    /// Milliseconds since the Unix epoch.
29    pub timestamp: f64,
30}
31impl LogEntry {
32    /// The template with its placeholders replaced by the values, in order.
33    pub fn message(&self) -> String {
34        format_template(&self.template, &self.values)
35    }
36    pub fn to_json(&self) -> Value {
37        json!({"sequence":self.sequence,"level":format!("{:?}",self.level),"area":self.area,"message":self.template,"values":self.values,"timestamp":self.timestamp})
38    }
39}
40
41struct Ring {
42    last: u64,
43    entries: VecDeque<LogEntry>,
44}
45static RING: Mutex<Ring> = Mutex::new(Ring {
46    last: 0,
47    entries: VecDeque::new(),
48});
49/// The installed tee and the number of guards that keep it.
50static INSTALLED: Mutex<Option<(Arc<CaptureSink>, usize)>> = Mutex::new(None);
51/// The lowest level that is captured, as the discriminant of [`LogEventLevel`].
52static MINIMUM: AtomicI32 = AtomicI32::new(DEFAULT_MINIMUM as i32);
53
54/// The process-wide capture. Entries are recorded only while a guard of [`LogCapture::install`] is
55/// alive; the ring keeps the last 1024.
56pub struct LogCapture;
57impl LogCapture {
58    /// Installs the tee, or keeps the installed one for one more guard.
59    pub fn install() -> LogGuard {
60        let mut installed = INSTALLED.lock().unwrap_or_else(|e| e.into_inner());
61        if let Some((sink, owners)) = installed.as_mut() {
62            let ours: Arc<dyn ILogSink + Send + Sync> = sink.clone();
63            if Logger::sink().is_some_and(|current| Arc::ptr_eq(&current, &ours)) {
64                *owners += 1;
65                return LogGuard(());
66            }
67        }
68        let sink = Arc::new(CaptureSink {
69            previous: Logger::sink(),
70        });
71        Logger::set_sink(Some(sink.clone()));
72        *installed = Some((sink, 1));
73        LogGuard(())
74    }
75    /// Captures events from `level` up while the tee is installed (Information by default).
76    pub fn capture_from(level: LogEventLevel) {
77        MINIMUM.fetch_min(level as i32, Ordering::AcqRel);
78    }
79    /// The entries after `cursor`; `cursor` moves to the last recorded entry.
80    pub fn since(cursor: &mut u64) -> Vec<LogEntry> {
81        let ring = RING.lock().unwrap_or_else(|e| e.into_inner());
82        let entries = ring
83            .entries
84            .iter()
85            .filter(|e| e.sequence > *cursor)
86            .cloned()
87            .collect();
88        *cursor = ring.last;
89        entries
90    }
91    /// `{"cursor", "entries"}` of the entries after `after`.
92    pub fn snapshot(after: u64) -> Value {
93        let mut cursor = after;
94        let entries: Vec<_> = Self::since(&mut cursor)
95            .iter()
96            .map(LogEntry::to_json)
97            .collect();
98        json!({"cursor":cursor.max(after),"entries":entries})
99    }
100}
101
102/// Keeps the tee installed. The previous sink is restored when the last guard is dropped, if the
103/// tee is still the current sink.
104pub struct LogGuard(());
105impl Drop for LogGuard {
106    fn drop(&mut self) {
107        let mut installed = INSTALLED.lock().unwrap_or_else(|e| e.into_inner());
108        let Some((sink, owners)) = installed.as_mut() else {
109            return;
110        };
111        *owners -= 1;
112        if *owners > 0 {
113            return;
114        }
115        let ours: Arc<dyn ILogSink + Send + Sync> = sink.clone();
116        if Logger::sink().is_some_and(|current| Arc::ptr_eq(&current, &ours)) {
117            Logger::set_sink(sink.previous.clone());
118        }
119        *installed = None;
120        MINIMUM.store(DEFAULT_MINIMUM as i32, Ordering::Release);
121    }
122}
123
124struct CaptureSink {
125    previous: Option<Arc<dyn ILogSink + Send + Sync>>,
126}
127fn captured(level: LogEventLevel) -> bool {
128    level as i32 >= MINIMUM.load(Ordering::Acquire)
129}
130fn record(level: LogEventLevel, area: &str, template: &str, values: &[&dyn Display]) {
131    if !captured(level) {
132        return;
133    }
134    let timestamp = SystemTime::now()
135        .duration_since(UNIX_EPOCH)
136        .unwrap_or_default()
137        .as_secs_f64()
138        * 1000.0;
139    let mut ring = RING.lock().unwrap_or_else(|e| e.into_inner());
140    ring.last += 1;
141    let entry = LogEntry {
142        sequence: ring.last,
143        level,
144        area: area.chars().take(256).collect(),
145        template: template.chars().take(8192).collect(),
146        values: values
147            .iter()
148            .take(32)
149            .map(|v| v.to_string().chars().take(8192).collect())
150            .collect(),
151        timestamp,
152    };
153    ring.entries.push_back(entry);
154    while ring.entries.len() > CAPACITY {
155        ring.entries.pop_front();
156    }
157}
158impl ILogSink for CaptureSink {
159    fn is_enabled(&self, level: LogEventLevel, area: &str) -> bool {
160        captured(level)
161            || self
162                .previous
163                .as_ref()
164                .is_some_and(|p| p.is_enabled(level, area))
165    }
166    fn log(&self, level: LogEventLevel, area: &str, source: Option<&dyn Any>, message: &str) {
167        record(level, area, message, &[]);
168        if let Some(sink) = self.previous.as_ref().filter(|p| p.is_enabled(level, area)) {
169            sink.log(level, area, source, message);
170        }
171    }
172    fn log_with_values(
173        &self,
174        level: LogEventLevel,
175        area: &str,
176        source: Option<&dyn Any>,
177        message: &str,
178        values: &[&dyn Display],
179    ) {
180        record(level, area, message, values);
181        if let Some(sink) = self.previous.as_ref().filter(|p| p.is_enabled(level, area)) {
182            sink.log_with_values(level, area, source, message, values);
183        }
184    }
185}
186
187/// Replaces the placeholders of the template (`{Name}`) with the values in order. The text of a
188/// value is not searched for placeholders again.
189fn format_template(template: &str, values: &[String]) -> String {
190    let mut result = String::with_capacity(template.len());
191    let mut values = values.iter();
192    let mut rest = template;
193    while let Some(start) = rest.find('{') {
194        let Some(length) = rest[start..].find('}') else {
195            break;
196        };
197        result.push_str(&rest[..start]);
198        match values.next() {
199            Some(value) => result.push_str(value),
200            None => result.push_str(&rest[start..start + length + 1]),
201        }
202        rest = &rest[start + length + 1..];
203    }
204    result.push_str(rest);
205    result
206}
207
208#[cfg(test)]
209mod tests {
210    use super::*;
211    // The ring and the tee are process state, shared with the other tests of this module.
212    static LOCK: Mutex<()> = Mutex::new(());
213
214    #[test]
215    fn ring_is_bounded_and_cursor_reads_only_new_entries() {
216        let _lock = LOCK.lock().unwrap_or_else(|e| e.into_inner());
217        let mut start = 0;
218        LogCapture::since(&mut start);
219        for i in 0..1100 {
220            record(LogEventLevel::Warning, "Binding", "Failure {Value}", &[&i]);
221        }
222        let snapshot = LogCapture::snapshot(start);
223        assert_eq!(snapshot["cursor"], start + 1100);
224        assert_eq!(snapshot["entries"].as_array().unwrap().len(), 1024);
225        assert_eq!(
226            LogCapture::snapshot(start + 1099)["entries"]
227                .as_array()
228                .unwrap()
229                .len(),
230            1
231        );
232        assert_eq!(LogCapture::snapshot(start + 1100)["entries"], json!([]));
233        record(LogEventLevel::Debug, "Binding", "below the minimum", &[]);
234        assert_eq!(LogCapture::snapshot(start + 1100)["entries"], json!([]));
235    }
236
237    #[test]
238    fn values_with_braces_do_not_shift_the_placeholders() {
239        assert_eq!(
240            format_template("{A} and {B}", &["{x}".into(), "y".into()]),
241            "{x} and y"
242        );
243        assert_eq!(format_template("{A} {B}", &["1".into()]), "1 {B}");
244        assert_eq!(format_template("no placeholder {", &[]), "no placeholder {");
245    }
246
247    #[test]
248    fn guards_share_one_tee_and_restore_the_previous_sink() {
249        let _lock = LOCK.lock().unwrap_or_else(|e| e.into_inner());
250        let previous = Logger::sink();
251        let first = LogCapture::install();
252        let sink = Logger::sink().unwrap();
253        let second = LogCapture::install();
254        assert!(Arc::ptr_eq(&sink, &Logger::sink().unwrap()));
255        assert!(!sink.is_enabled(LogEventLevel::Debug, "Any") || previous.is_some());
256        LogCapture::capture_from(LogEventLevel::Debug);
257        assert!(sink.is_enabled(LogEventLevel::Debug, "Any"));
258        drop(first);
259        assert!(Arc::ptr_eq(&sink, &Logger::sink().unwrap()));
260        drop(second);
261        assert_eq!(Logger::sink().is_some(), previous.is_some());
262        assert!(!captured(LogEventLevel::Debug));
263    }
264}
ferroui_inspect/logs.rs

ferroui_inspect/
logs.rs
