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

captains_log/
ring.rs
