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::cell::UnsafeCell;
10use std::hash::{Hash, Hasher};
11use std::io::Write;
12use std::mem::transmute;
13use std::path::{Path, PathBuf};
14use std::sync::atomic::{AtomicBool, Ordering};
15
16/// The LogRingFile sink is a tool for debugging deadlock or race condition,
17/// when the problem cannot be reproduce with ordinary log (because disk I/O will slow down the
18/// execution and prevent the bug to occur).
19///
20/// # Usage
21///
22/// Enable feature `ringfile` in your Cargo.toml.
23///
24/// Replace the log setup with the following in your test case:
25///
26///(Set the level to Info or higher, to turn of other debugging logs.)
27/// ``` rust
28/// use captains_log::*;
29/// recipe::ring_file("/tmp/ring.log", 512*1024*1024, Level::Info,
30///     signal_consts::SIGHUP).test().build().expect("log setup");
31/// ```
32///
33/// Then add some high-level log to critical path in the code, try to reproduce the problem, and
34/// reduce the amount of log if the bug not occur.
35///
36/// On start-up, it will create a limited-size ring-buffer-like memory. The log content will be hold within memory but
37/// not written to disk, old logs will be overwritten by new ones. Until specified signal arrives, the last
38/// part of log message will be dumped to file, in time order.
39///
40/// Once your program hangs up completely , find your process pid and send a signal to it.
41///
42/// ``` shell
43/// kill -SIGHUP <pid>
44/// ```
45/// There will be messages print to stdout:
46///
47/// ``` text
48/// RingFile: start dumping
49/// RingFile: dump complete
50/// ```
51///
52/// Then you can inspect your log content on disk (for this example `/tmp/ring.log`).
53///
54/// The backend is provided by [RingFile crate](https://docs.rs/ring-file). To ensure low
55/// latency, the buffer is protected by a spinlock instead of a mutex. After the program hangs, because
56/// no more message will be written to the buffer, log content can be safely copied from the buffer area to disk.
57///
58/// Be aware that it did not use mlock to prevent memory being swapping. (Swapping might make the
59/// 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`.
60///
61/// A real-life debugging story can be found on <https://github.com/frostyplanet/crossfire-rs/issues/24>.
62#[derive(Hash)]
63pub struct LogRingFile {
64    pub file_path: Box<Path>,
65    pub level: Level,
66    pub format: LogFormat,
67    /// 0 < buf_size < i32::MAX
68    pub buf_size: i32,
69}
70
71impl LogRingFile {
72    pub fn new<P: Into<PathBuf>>(
73        file_path: P, buf_size: i32, max_level: Level, format: LogFormat,
74    ) -> Self {
75        assert!(buf_size > 0);
76        Self { buf_size, file_path: file_path.into().into_boxed_path(), level: max_level, format }
77    }
78}
79
80impl SinkConfigBuild for LogRingFile {
81    fn build(&self) -> LogSink {
82        LogSink::RingFile(LogSinkRingFile::new(self))
83    }
84}
85
86impl SinkConfigTrait for LogRingFile {
87    fn get_level(&self) -> Level {
88        self.level
89    }
90
91    fn get_file_path(&self) -> Option<Box<Path>> {
92        Some(self.file_path.clone())
93    }
94
95    fn write_hash(&self, hasher: &mut Box<dyn Hasher>) {
96        self.hash(hasher);
97        hasher.write(b"LogRingFile");
98    }
99}
100
101pub(crate) struct LogSinkRingFile {
102    max_level: Level,
103    inner: UnsafeCell<RingFile>,
104    formatter: LogFormat,
105    /// In order to be fast, use a spin lock instead of Mutex
106    locked: AtomicBool,
107}
108
109unsafe impl Send for LogSinkRingFile {}
110unsafe impl Sync for LogSinkRingFile {}
111
112impl LogSinkRingFile {
113    fn new(config: &LogRingFile) -> Self {
114        Self {
115            max_level: config.level,
116            inner: UnsafeCell::new(RingFile::new(config.buf_size, config.file_path.to_path_buf())),
117            formatter: config.format.clone(),
118            locked: AtomicBool::new(false),
119        }
120    }
121
122    #[inline(always)]
123    fn get_inner(&self) -> &RingFile {
124        unsafe { transmute(self.inner.get()) }
125    }
126
127    #[inline(always)]
128    fn get_inner_mut(&self) -> &mut RingFile {
129        unsafe { transmute(self.inner.get()) }
130    }
131}
132
133impl LogSinkTrait for LogSinkRingFile {
134    fn open(&self) -> std::io::Result<()> {
135        Ok(())
136    }
137
138    fn reopen(&self) -> std::io::Result<()> {
139        println!("RingFile: start dumping");
140        if let Err(e) = self.get_inner().dump() {
141            println!("RingFile: dump error {:?}", e);
142            Err(e)
143        } else {
144            println!("RingFile: dump complete");
145            Ok(())
146        }
147    }
148
149    #[inline(always)]
150    fn log(&self, now: &Timer, r: &Record) {
151        if r.level() <= self.max_level {
152            let buf = self.formatter.process(now, r);
153            while self
154                .locked
155                .compare_exchange_weak(false, true, Ordering::SeqCst, Ordering::Relaxed)
156                .is_err()
157            {
158                std::hint::spin_loop();
159            }
160            let _ = self.get_inner_mut().write_all(buf.as_bytes());
161            self.locked.store(false, Ordering::Release);
162        }
163    }
164
165    #[inline(always)]
166    fn flush(&self) {}
167}
captains_log/ring.rs

captains_log/
ring.rs
