vanguards_rs/
logguard.rs

1//! Log monitoring for attacks, protocol issues, and debugging.
2//!
3//! This module provides log monitoring functionality that buffers recent Tor log
4//! messages and dumps them when circuits are closed, helping with debugging and
5//! attack detection.
6//!
7//! # Overview
8//!
9//! The logguard system:
10//!
11//! - **Buffers log messages**: Keeps recent log entries up to a configurable limit
12//! - **Dumps on circuit close**: Outputs buffered logs before and after circuit closure
13//! - **Monitors warnings**: Logs Tor WARN-level messages at NOTICE level
14//! - **Enables ProtocolWarnings**: Optionally enables Tor's ProtocolWarnings setting
15//!
16//! # Configuration
17//!
18//! Key configuration options in [`crate::config::LogguardConfig`]:
19//!
20//! | Option | Default | Description |
21//! |--------|---------|-------------|
22//! | `protocol_warns` | true | Enable ProtocolWarnings in Tor |
23//! | `dump_limit` | 25 | Maximum log entries to buffer |
24//! | `dump_level` | NOTICE | Minimum log level to buffer |
25//!
26//! # What This Module Does NOT Do
27//!
28//! - **Log rotation**: Use external tools for log file management
29//! - **Log persistence**: Buffered logs are lost on restart
30//! - **Attack prevention**: This module aids debugging, not prevention
31//!
32//! # See Also
33//!
34//! - [`crate::config::LogguardConfig`] - Configuration options
35//! - [`crate::logger`] - Main logging infrastructure
36//! - [Python vanguards logguard](https://github.com/mikeperry-tor/vanguards)
37
38use std::collections::VecDeque;
39use std::time::{SystemTime, UNIX_EPOCH};
40
41use crate::config::{LogLevel, LogguardConfig};
42use crate::logger::plog;
43
44/// A buffered log entry from Tor.
45///
46/// Contains the log level, message content, and arrival timestamp.
47/// Entries are stored in a ring buffer and dumped when circuits are closed.
48///
49/// # Fields
50///
51/// * `runlevel` - The log level (DEBUG, INFO, NOTICE, WARN, ERR)
52/// * `message` - The log message content
53/// * `arrived_at` - Unix timestamp when the log entry arrived
54///
55/// # Example
56///
57/// ```rust
58/// use vanguards_rs::logguard::LogEntry;
59///
60/// // Create entry with current timestamp
61/// let entry = LogEntry::new("NOTICE", "Circuit 123 built");
62/// assert_eq!(entry.runlevel, "NOTICE");
63/// assert_eq!(entry.message, "Circuit 123 built");
64///
65/// // Create entry with specific timestamp
66/// let entry = LogEntry::with_timestamp("WARN", "Connection lost", 1234567890.5);
67/// println!("{}", entry.format());
68/// ```
69///
70/// # See Also
71///
72/// - [`LogGuard`] - Container for log entries
73#[derive(Debug, Clone)]
74pub struct LogEntry {
75    /// The log level (DEBUG, INFO, NOTICE, WARN, ERR).
76    pub runlevel: String,
77    /// The log message content.
78    pub message: String,
79    /// Unix timestamp when the log entry arrived.
80    pub arrived_at: f64,
81}
82
83impl LogEntry {
84    /// Creates a new log entry with the current timestamp.
85    pub fn new(runlevel: &str, message: &str) -> Self {
86        let arrived_at = SystemTime::now()
87            .duration_since(UNIX_EPOCH)
88            .unwrap_or_default()
89            .as_secs_f64();
90        Self {
91            runlevel: runlevel.to_string(),
92            message: message.to_string(),
93            arrived_at,
94        }
95    }
96
97    /// Creates a new log entry with a specific timestamp.
98    pub fn with_timestamp(runlevel: &str, message: &str, arrived_at: f64) -> Self {
99        Self {
100            runlevel: runlevel.to_string(),
101            message: message.to_string(),
102            arrived_at,
103        }
104    }
105
106    /// Formats the log entry for output.
107    pub fn format(&self) -> String {
108        let time_str = format_timestamp(self.arrived_at);
109        format!("TOR_{}[{}]: {}", self.runlevel, time_str, self.message)
110    }
111}
112
113/// Formats a Unix timestamp as a human-readable string.
114fn format_timestamp(timestamp: f64) -> String {
115    use chrono::DateTime;
116    let secs = timestamp as i64;
117    let nsecs = ((timestamp - secs as f64) * 1_000_000_000.0) as u32;
118    if let Some(dt) = DateTime::from_timestamp(secs, nsecs) {
119        dt.format("%a %b %e %H:%M:%S %Y").to_string()
120    } else {
121        format!("{:.3}", timestamp)
122    }
123}
124
125/// Log monitoring state.
126///
127/// Buffers recent Tor log messages and provides functionality to dump them
128/// when circuits are closed for debugging purposes.
129///
130/// # Buffer Behavior
131///
132/// The log buffer operates as a ring buffer with a configurable maximum size.
133/// When the buffer is full, the oldest entries are discarded to make room
134/// for new ones.
135///
136/// # Example
137///
138/// ```rust
139/// use vanguards_rs::logguard::LogGuard;
140/// use vanguards_rs::config::LogguardConfig;
141///
142/// let config = LogguardConfig::default();
143/// let mut guard = LogGuard::new(&config);
144///
145/// // Buffer log entries
146/// guard.log_event("NOTICE", "Circuit 123 built");
147/// guard.log_event("INFO", "Stream attached");
148/// assert_eq!(guard.buffer_len(), 2);
149///
150/// // Dump logs before circuit close
151/// guard.dump_log_queue("123", "Pre");
152/// assert_eq!(guard.buffer_len(), 0);
153/// ```
154///
155/// # Event Handling
156///
157/// The guard responds to circuit events:
158///
159/// - On `CLOSED` or `FAILED` with reason `REQUESTED`: Dumps buffered logs
160/// - This captures context around intentional circuit closures
161///
162/// # See Also
163///
164/// - [`LogEntry`] - Individual log entries
165/// - [`crate::config::LogguardConfig`] - Configuration options
166/// - [`crate::logger`] - Main logging infrastructure
167#[derive(Debug, Clone)]
168pub struct LogGuard {
169    /// Buffered log entries.
170    pub log_buffer: VecDeque<LogEntry>,
171    /// Minimum log level to buffer.
172    pub log_level: LogLevel,
173    /// Maximum number of entries to buffer.
174    pub log_limit: usize,
175}
176
177impl LogGuard {
178    /// Creates a new LogGuard with the specified configuration.
179    pub fn new(config: &LogguardConfig) -> Self {
180        Self {
181            log_buffer: VecDeque::new(),
182            log_level: config.dump_level,
183            log_limit: config.dump_limit,
184        }
185    }
186
187    /// Handles a log event from Tor.
188    ///
189    /// Buffers the log entry if it meets the minimum log level requirement.
190    /// Automatically trims the buffer if it exceeds the configured limit.
191    ///
192    /// # Arguments
193    ///
194    /// * `runlevel` - The log level (DEBUG, INFO, NOTICE, WARN, ERR)
195    /// * `message` - The log message content
196    pub fn log_event(&mut self, runlevel: &str, message: &str) {
197        let entry = LogEntry::new(runlevel, message);
198        self.log_buffer.push_back(entry);
199
200        while self.log_buffer.len() > self.log_limit {
201            self.log_buffer.pop_front();
202        }
203    }
204
205    /// Handles a log event with a specific timestamp.
206    pub fn log_event_with_timestamp(&mut self, runlevel: &str, message: &str, arrived_at: f64) {
207        let entry = LogEntry::with_timestamp(runlevel, message, arrived_at);
208        self.log_buffer.push_back(entry);
209
210        while self.log_buffer.len() > self.log_limit {
211            self.log_buffer.pop_front();
212        }
213    }
214
215    /// Handles a WARN-level log event.
216    ///
217    /// Logs the warning at NOTICE level for visibility.
218    pub fn log_warn_event(&self, message: &str) {
219        plog(LogLevel::Notice, &format!("Tor log warn: {}", message));
220    }
221
222    /// Dumps the log buffer for a circuit close event.
223    ///
224    /// This is called before and after circuit close. The "when" argument is
225    /// "Pre" before we close a circuit and "Post" after.
226    ///
227    /// # Arguments
228    ///
229    /// * `circ_id` - The circuit ID being closed
230    /// * `when` - "Pre" for before close, "Post" for after close
231    pub fn dump_log_queue(&mut self, circ_id: &str, when: &str) {
232        while let Some(entry) = self.log_buffer.pop_front() {
233            plog(
234                LogLevel::Notice,
235                &format!(
236                    "{}-close CIRC ID={} Tor log: {}",
237                    when,
238                    circ_id,
239                    entry.format()
240                ),
241            );
242        }
243    }
244
245    /// Handles a circuit event for post-close log dumping.
246    ///
247    /// Dumps buffered logs after a circuit is closed with REQUESTED reason.
248    ///
249    /// # Arguments
250    ///
251    /// * `circ_id` - The circuit ID
252    /// * `status` - The circuit status (CLOSED, FAILED, etc.)
253    /// * `reason` - The close reason
254    pub fn circ_event(&mut self, circ_id: &str, status: &str, reason: Option<&str>) {
255        if (status == "CLOSED" || status == "FAILED") && reason == Some("REQUESTED") {
256            self.dump_log_queue(circ_id, "Post");
257        }
258    }
259
260    /// Returns the number of buffered log entries.
261    pub fn buffer_len(&self) -> usize {
262        self.log_buffer.len()
263    }
264
265    /// Clears the log buffer.
266    pub fn clear(&mut self) {
267        self.log_buffer.clear();
268    }
269
270    /// Returns the log levels that should be subscribed to based on dump_level.
271    ///
272    /// Returns a list of Tor event types to subscribe to.
273    pub fn get_log_event_types(dump_level: LogLevel) -> Vec<&'static str> {
274        let mut events = Vec::new();
275
276        if dump_level <= LogLevel::Debug {
277            events.push("DEBUG");
278        }
279        if dump_level <= LogLevel::Info {
280            events.push("INFO");
281        }
282        if dump_level <= LogLevel::Notice {
283            events.push("NOTICE");
284        }
285        if dump_level <= LogLevel::Warn {
286            events.push("WARN");
287        }
288        if dump_level <= LogLevel::Error {
289            events.push("ERR");
290        }
291
292        events
293    }
294}
295
296#[cfg(test)]
297mod tests {
298    use super::*;
299
300    #[test]
301    fn test_log_entry_new() {
302        let entry = LogEntry::new("NOTICE", "Test message");
303        assert_eq!(entry.runlevel, "NOTICE");
304        assert_eq!(entry.message, "Test message");
305        assert!(entry.arrived_at > 0.0);
306    }
307
308    #[test]
309    fn test_log_entry_with_timestamp() {
310        let entry = LogEntry::with_timestamp("WARN", "Warning", 1234567890.5);
311        assert_eq!(entry.runlevel, "WARN");
312        assert_eq!(entry.message, "Warning");
313        assert!((entry.arrived_at - 1234567890.5).abs() < 0.001);
314    }
315
316    #[test]
317    fn test_log_entry_format() {
318        let entry = LogEntry::with_timestamp("NOTICE", "Test", 1234567890.0);
319        let formatted = entry.format();
320        assert!(formatted.contains("TOR_NOTICE"));
321        assert!(formatted.contains("Test"));
322    }
323
324    #[test]
325    fn test_logguard_new() {
326        let config = LogguardConfig::default();
327        let guard = LogGuard::new(&config);
328        assert_eq!(guard.log_limit, 25);
329        assert_eq!(guard.log_level, LogLevel::Notice);
330        assert!(guard.log_buffer.is_empty());
331    }
332
333    #[test]
334    fn test_logguard_log_event() {
335        let config = LogguardConfig::default();
336        let mut guard = LogGuard::new(&config);
337
338        guard.log_event("NOTICE", "Test message 1");
339        guard.log_event("WARN", "Test message 2");
340
341        assert_eq!(guard.buffer_len(), 2);
342    }
343
344    #[test]
345    fn test_logguard_buffer_limit() {
346        let config = LogguardConfig {
347            dump_limit: 3,
348            ..Default::default()
349        };
350        let mut guard = LogGuard::new(&config);
351
352        for i in 0..5 {
353            guard.log_event("NOTICE", &format!("Message {}", i));
354        }
355
356        assert_eq!(guard.buffer_len(), 3);
357        let first = guard.log_buffer.front().unwrap();
358        assert_eq!(first.message, "Message 2");
359    }
360
361    #[test]
362    fn test_logguard_clear() {
363        let config = LogguardConfig::default();
364        let mut guard = LogGuard::new(&config);
365
366        guard.log_event("NOTICE", "Test");
367        assert_eq!(guard.buffer_len(), 1);
368
369        guard.clear();
370        assert_eq!(guard.buffer_len(), 0);
371    }
372
373    #[test]
374    fn test_get_log_event_types_debug() {
375        let events = LogGuard::get_log_event_types(LogLevel::Debug);
376        assert!(events.contains(&"DEBUG"));
377        assert!(events.contains(&"INFO"));
378        assert!(events.contains(&"NOTICE"));
379        assert!(events.contains(&"WARN"));
380        assert!(events.contains(&"ERR"));
381    }
382
383    #[test]
384    fn test_get_log_event_types_notice() {
385        let events = LogGuard::get_log_event_types(LogLevel::Notice);
386        assert!(!events.contains(&"DEBUG"));
387        assert!(!events.contains(&"INFO"));
388        assert!(events.contains(&"NOTICE"));
389        assert!(events.contains(&"WARN"));
390        assert!(events.contains(&"ERR"));
391    }
392
393    #[test]
394    fn test_get_log_event_types_error() {
395        let events = LogGuard::get_log_event_types(LogLevel::Error);
396        assert!(!events.contains(&"DEBUG"));
397        assert!(!events.contains(&"INFO"));
398        assert!(!events.contains(&"NOTICE"));
399        assert!(!events.contains(&"WARN"));
400        assert!(events.contains(&"ERR"));
401    }
402
403    #[test]
404    fn test_logguard_init() {
405        let config = LogguardConfig {
406            dump_level: LogLevel::Debug,
407            dump_limit: 25,
408            protocol_warns: true,
409        };
410        let lg = LogGuard::new(&config);
411
412        assert_eq!(lg.buffer_len(), 0);
413    }
414
415    #[test]
416    fn test_log_event_buffering() {
417        let config = LogguardConfig::default();
418        let mut lg = LogGuard::new(&config);
419
420        lg.log_event("WARN", "whatever");
421        assert_eq!(lg.buffer_len(), 1);
422    }
423
424    #[test]
425    fn test_circ_event_clears_buffer() {
426        let config = LogguardConfig::default();
427        let mut lg = LogGuard::new(&config);
428
429        lg.log_event("WARN", "whatever");
430        assert_eq!(lg.buffer_len(), 1);
431
432        lg.circ_event("2", "FAILED", Some("REQUESTED"));
433        assert_eq!(lg.buffer_len(), 0);
434    }
435
436    #[test]
437    fn test_circ_event_non_requested_doesnt_clear() {
438        let config = LogguardConfig::default();
439        let mut lg = LogGuard::new(&config);
440
441        lg.log_event("WARN", "whatever");
442        assert_eq!(lg.buffer_len(), 1);
443
444        lg.circ_event("2", "CLOSED", Some("FINISHED"));
445        assert_eq!(lg.buffer_len(), 1);
446    }
447
448    #[test]
449    fn test_buffer_limit_from_unit() {
450        let config = LogguardConfig {
451            dump_limit: 25,
452            ..Default::default()
453        };
454        let mut lg = LogGuard::new(&config);
455
456        for i in 0..(2 * config.dump_limit) {
457            lg.log_event("WARN", &format!("message {}", i));
458        }
459
460        assert_eq!(lg.buffer_len(), config.dump_limit);
461    }
462
463    #[test]
464    fn test_closing_circuit_with_empty_log() {
465        let config = LogguardConfig::default();
466        let mut lg = LogGuard::new(&config);
467
468        lg.circ_event("3", "FAILED", Some("REQUESTED"));
469        assert_eq!(lg.buffer_len(), 0);
470    }
471
472    #[test]
473    fn test_buffer_fifo_order() {
474        let config = LogguardConfig {
475            dump_limit: 3,
476            ..Default::default()
477        };
478        let mut lg = LogGuard::new(&config);
479
480        for i in 0..5 {
481            lg.log_event("NOTICE", &format!("Message {}", i));
482        }
483
484        assert_eq!(lg.buffer_len(), 3);
485        let first = lg.log_buffer.front().unwrap();
486        assert_eq!(first.message, "Message 2");
487    }
488}