captains_log/
ring.rs

1use crate::{
2    config::{LogFormat, SinkConfigBuild, SinkConfigTrait},
3    log_impl::{LogSink, LogSinkTrait},
4    time::Timer,
5};
6use log::*;
7use ring_file::*;
8
9use std::hash::{Hash, Hasher};
10use std::path::Path;
11
12/// The LogRingFile sink is a way to minimize the cost of logging, for debugging deadlock or race condition,
13/// when the problem cannot be reproduce with ordinary log (because disk I/O will slow down the
14/// execution and prevent the bug to occur).
15///
16/// # Usage
17///
18/// Enable feature `ringfile` in your Cargo.toml.
19///
20/// Replace the log setup with the following [recipe::ring_file()](crate::recipe::ring_file()) in your test case:
21///
22///(Set the level to Info or higher, to turn off other debugging logs.)
23///
24/// ``` rust
25/// use captains_log::*;
26/// // the recipe already register signal and dynamic=true, do not use test(),
27/// // because test() will clear the signal.
28/// recipe::ring_file("/tmp/ring.log", 1024*1024, Level::Info,
29///     signal_consts::SIGHUP).build().expect("log setup");
30/// ```
31///
32/// # Debugging deadlocks
33///
34/// Then add some high-level log to critical path in the code, try to reproduce the problem, and
35/// reduce the amount of log if the bug not occur.
36///
37/// On start-up, it will create a limited-size ring-buffer-like memory. The log content will be held within memory but
38/// not written to disk, old logs will be overwritten by new ones. Until specified signal arrives, the last
39/// part of log message will be dumped to the file, in time order.
40///
41/// Once your program hangs up completely, find your process PID and send a signal to it.
42///
43/// ``` shell
44/// kill -SIGHUP <pid>
45/// ```
46/// There will be messages printed to stdout:
47///
48/// ``` text
49/// RingFile: start dumping
50/// RingFile: dump complete
51/// ```
52/// Then you can inspect your log content on disk (for this example `/tmp/ring.log`).
53///
54/// A real-life debugging story can be found on <https://github.com/frostyplanet/crossfire-rs/issues/24>.
55///
56/// # Debugging assertions
57///
58/// When you debugging the reason of some unexpected assertions, it will automatically trigger the
59/// dump in our panic hook. If you want an explicit dump, you can call:
60/// ``` rust
61///    log::logger().flush();
62/// ```
63///
64/// # NOTE
65///
66/// The backend is provided by [RingFile crate](https://docs.rs/ring-file). To ensure low
67/// latency, the buffers are put in thread local. After the program hangs, or panic, because
68/// no more messages will be written to the buffer, log content can be safely copied from the buffer area to disk.
69///
70/// Be aware that it did not use mlock to prevent memory from being swapping. (Swapping might make the
71/// code slow to prevent bug reproduction). When your memory is not enough, use a smaller buf_size and turn off the swap with `swapoff -a`.
72///
73/// The collected logs are from all the threads, including those exited. That means there might be
74/// very old contents mixed with newer contents. We suggest you log before thread exits. And also
75/// note that thread_id is reused after thread exits.
76#[derive(Hash)]
77pub struct LogRingFile {
78    pub file_path: Option<Box<Path>>,
79    pub level: Level,
80    pub format: LogFormat,
81    /// 0 < buf_size < i32::MAX, note this is the buffer size within each thread.
82    pub buf_size: i32,
83}
84
85impl LogRingFile {
86    pub fn new(
87        file_path: Option<Box<Path>>, buf_size: i32, max_level: Level, format: LogFormat,
88    ) -> Self {
89        assert!(buf_size > 0);
90        Self { buf_size, file_path, level: max_level, format }
91    }
92}
93
94impl SinkConfigBuild for LogRingFile {
95    fn build(&self) -> LogSink {
96        LogSink::RingFile(LogSinkRingFile::new(self))
97    }
98}
99
100impl SinkConfigTrait for LogRingFile {
101    fn get_level(&self) -> Level {
102        self.level
103    }
104
105    fn get_file_path(&self) -> Option<Box<Path>> {
106        self.file_path.clone()
107    }
108
109    fn write_hash(&self, hasher: &mut Box<dyn Hasher>) {
110        self.hash(hasher);
111        hasher.write(b"LogRingFile");
112    }
113}
114
115pub(crate) struct LogSinkRingFile {
116    max_level: Level,
117    formatter: LogFormat,
118    ring: RingFile,
119}
120
121impl LogSinkRingFile {
122    fn new(config: &LogRingFile) -> Self {
123        Self {
124            max_level: config.level,
125            formatter: config.format.clone(),
126            ring: RingFile::new(config.buf_size as usize, config.file_path.clone()),
127        }
128    }
129}
130
131impl LogSinkTrait for LogSinkRingFile {
132    fn open(&self) -> std::io::Result<()> {
133        println!("ringfile is on");
134        Ok(())
135    }
136
137    fn reopen(&self) -> std::io::Result<()> {
138        println!("RingFile: start dumping");
139        if let Err(e) = self.ring.dump() {
140            println!("RingFile: dump error {:?}", e);
141            return Err(e);
142        }
143        println!("RingFile: dump complete");
144        Ok(())
145    }
146
147    #[inline(always)]
148    fn log(&self, now: &Timer, r: &Record) {
149        if r.level() <= self.max_level {
150            let (ts, content) = self.formatter.process_with_timestamp(now, r);
151            self.ring.write(ts, content);
152        }
153    }
154
155    /// Manually dump the log
156    #[inline(always)]
157    fn flush(&self) {
158        let _ = self.reopen();
159    }
160}
captains_log/ring.rs

captains_log/
ring.rs
