drive_abci/logging/
mod.rs

1mod config;
2mod destination;
3mod error;
4mod format;
5mod level;
6mod logger;
7
8pub use config::LogConfig;
9pub use config::LogConfigs;
10pub use destination::LogDestination;
11pub use error::Error;
12pub use format::LogFormat;
13pub use level::LogLevel;
14pub use logger::LogBuilder;
15pub use logger::Loggers;
16
17fn should_emit_test_logs_to_stdout() -> bool {
18    let step_debug = std::env::var("ACTIONS_STEP_DEBUG")
19        .map(|value| value == "true")
20        .unwrap_or(false);
21    let runner_debug = std::env::var("ACTIONS_RUNNER_DEBUG")
22        .map(|value| value == "true")
23        .unwrap_or(false);
24
25    step_debug || runner_debug
26}
27
28/// Helper that initializes logging in unit tests
29///
30///
31/// For verbosity, see drive-abci --help or use 0 or 5
32pub fn init_for_tests(level: LogLevel) {
33    let mut logger_builder = LogBuilder::new();
34    let destination = if should_emit_test_logs_to_stdout() {
35        LogDestination::StdOut
36    } else {
37        LogDestination::TestWriter
38    };
39    let config = LogConfig {
40        destination,
41        level,
42        color: None,
43        format: LogFormat::Full,
44        max_files: 0,
45    };
46
47    logger_builder
48        .add("default", &config)
49        .expect("cannot configure default logger");
50
51    logger_builder.build().try_install().ok();
52}
53
54#[cfg(test)]
55mod tests {
56    use super::*;
57
58    use itertools::Itertools;
59    use std::{cmp::Ordering, fs};
60    use tempfile::TempDir;
61
62    /// Test that multiple loggers can work independently, with different log levels.
63    ///
64    /// Note that, due to limitation of [tracing::subscriber::set_global_default()], we can only have one test.
65    #[test]
66    fn test_logging() {
67        let logger_stdout = LogConfig {
68            destination: LogDestination::StdOut,
69            level: LogLevel::Info,
70            format: LogFormat::Pretty,
71            ..Default::default()
72        };
73
74        let logger_stderr = LogConfig {
75            destination: LogDestination::StdErr,
76            level: LogLevel::Debug,
77            ..Default::default()
78        };
79
80        let logger_v0 = LogConfig {
81            destination: LogDestination::Bytes,
82            level: LogLevel::Info,
83            ..Default::default()
84        };
85
86        let logger_v4 = LogConfig {
87            destination: LogDestination::Bytes,
88            level: LogLevel::Debug,
89            format: LogFormat::Json,
90            ..Default::default()
91        };
92
93        let dir = TempDir::new().unwrap();
94
95        let file_v0_path = dir.path().join("log.v0");
96        let logger_file_v0 = LogConfig {
97            destination: LogDestination::File(file_v0_path),
98            level: LogLevel::Info,
99            max_files: 4,
100            ..Default::default()
101        };
102
103        let file_v4_path = dir.path().join("log.v4");
104        let logger_file_v4 = LogConfig {
105            destination: LogDestination::File(file_v4_path.clone()),
106            level: LogLevel::Debug,
107            max_files: 0, // no rotation
108            ..Default::default()
109        };
110
111        let loggers = LogBuilder::new()
112            .with_config("stdout", &logger_stdout)
113            .unwrap()
114            .with_config("stderr", &logger_stderr)
115            .unwrap()
116            .with_config("v0", &logger_v0)
117            .unwrap()
118            .with_config("v4", &logger_v4)
119            .unwrap()
120            .with_config("file_v0", &logger_file_v0)
121            .unwrap()
122            .with_config("file_v4", &logger_file_v4)
123            .unwrap()
124            .build();
125
126        let dispatch = loggers.as_subscriber().expect("subscriber failed");
127        let _guard = tracing::dispatcher::set_default(&dispatch);
128
129        const TEST_STRING_DEBUG: &str = "testing debug trace";
130        const TEST_STRING_ERROR: &str = "testing error trace";
131        tracing::error!(TEST_STRING_ERROR);
132        tracing::debug!(TEST_STRING_DEBUG);
133
134        loggers.flush().unwrap();
135        loggers.rotate().unwrap();
136
137        // CHECK ASSERTIONS
138
139        let result_verb_0 = loggers
140            .get("v0")
141            .expect("should return logger")
142            .destination
143            .lock()
144            .unwrap()
145            .read_as_string();
146
147        let result_verb_4 = loggers
148            .get("v4")
149            .expect("should return logger")
150            .destination
151            .lock()
152            .unwrap()
153            .read_as_string();
154
155        let result_dir_verb_0 = loggers
156            .get("file_v0")
157            .expect("should return logger")
158            .destination
159            .lock()
160            .unwrap()
161            .read_as_string();
162
163        let result_file_verb_4 = fs::read_to_string(&file_v4_path)
164            .map_err(|e| panic!("{:?}: {:?}", file_v4_path.clone(), e.to_string()))
165            .unwrap();
166
167        assert!(result_verb_0.contains(TEST_STRING_ERROR));
168        assert!(result_dir_verb_0.contains(TEST_STRING_ERROR));
169        assert!(result_verb_4.contains(TEST_STRING_ERROR));
170        assert!(result_file_verb_4.contains(TEST_STRING_ERROR));
171
172        assert!(!result_verb_0.contains(TEST_STRING_DEBUG));
173        assert!(!result_dir_verb_0.contains(TEST_STRING_DEBUG));
174        assert!(result_verb_4.contains(TEST_STRING_DEBUG));
175        assert!(result_file_verb_4.contains(TEST_STRING_DEBUG));
176    }
177
178    /// Test rotation of RotationWriter destination.
179    ///
180    /// Given that the RotationWriter is rotated 3 times, we expect to see 4 files:
181    /// - 1 file with the original name
182    /// - 3 files with the original name and timestamp suffix
183    #[test]
184    fn test_rotation_writer_rotate() {
185        let temp_dir = TempDir::new().unwrap();
186        let filepath = temp_dir.path().join("drive-abci.log");
187        let config = LogConfig {
188            destination: LogDestination::File(filepath),
189            level: LogLevel::Trace,
190            format: LogFormat::Pretty,
191            max_files: 3,
192            ..Default::default()
193        };
194
195        let loggers = LogBuilder::new()
196            .with_config("rotate", &config)
197            .expect("configure log builder")
198            .build();
199        let logger = loggers.get("rotate").expect("get logger");
200
201        for i in 0..config.max_files + 2 {
202            logger
203                .destination
204                .lock()
205                .unwrap()
206                .to_write()
207                .write_all(format!("file {}\n", i).as_bytes())
208                .unwrap();
209
210            loggers.rotate().expect("rotate logs");
211
212            std::thread::sleep(std::time::Duration::from_millis(1100));
213        }
214        let mut counter = 0;
215        temp_dir.path().read_dir().unwrap().for_each(|entry| {
216            let entry = entry.unwrap();
217            let path = entry.path();
218            let path = path.to_string_lossy();
219            assert!(path.contains("drive-abci.log"));
220            counter += 1;
221        });
222        assert_eq!(counter, config.max_files + 1);
223    }
224
225    // TODO: Not passing on Mac OS
226    /// Test rotation of File destination.
227    ///
228    /// Given that we move the File and then Rotate it, we expect the file to be recreated in new location.
229    #[ignore]
230    #[test]
231    fn test_file_rotate() {
232        const ITERATIONS: usize = 4;
233
234        let temp_dir = TempDir::new().unwrap();
235        let filepath = temp_dir.path().join("drive-abci.log");
236        let config = LogConfig {
237            destination: LogDestination::File(filepath.clone()),
238            level: LogLevel::Trace,
239            format: LogFormat::Pretty,
240            max_files: 0,
241            ..Default::default()
242        };
243
244        let loggers = LogBuilder::new()
245            .with_config("rotate", &config)
246            .expect("configure log builder")
247            .build();
248        let logger = loggers.get("rotate").expect("get logger");
249
250        for i in 0..ITERATIONS {
251            let guard = logger.destination.lock().unwrap();
252            guard
253                .to_write()
254                .write_all(format!("file {}, before rotate\n", i).as_bytes())
255                .unwrap();
256
257            fs::rename(
258                &filepath,
259                temp_dir.path().join(format!("drive-abci.log.{}", i)),
260            )
261            .unwrap();
262            // rotate() locks, so we need to drop guard here
263            drop(guard);
264
265            loggers.rotate().expect("rotate logs");
266            let guard = logger.destination.lock().unwrap();
267            guard
268                .to_write()
269                .write_all(format!("file {}, after rotate\n", i + 1).as_bytes())
270                .unwrap();
271            guard.to_write().flush().unwrap();
272
273            std::thread::sleep(std::time::Duration::from_millis(10));
274        }
275
276        // Close all files, so that we can read them
277        drop(loggers);
278
279        let mut counter = 0;
280        temp_dir
281            .path()
282            .read_dir()
283            .unwrap()
284            .sorted_by(|a, b| {
285                let a = a.as_ref().unwrap().path();
286                let b = b.as_ref().unwrap().path();
287                if a.eq(&b) {
288                    return Ordering::Equal;
289                }
290                if a.ends_with("drive-abci.log") {
291                    return Ordering::Greater;
292                }
293                if b.ends_with("drive-abci.log") {
294                    return Ordering::Greater;
295                }
296
297                a.cmp(&b)
298            })
299            .for_each(|entry| {
300                let entry = entry.unwrap();
301                let path = entry.path();
302                let path_str = path.to_string_lossy();
303                let read = fs::read_to_string(&path).unwrap();
304                assert!(path_str.contains("drive-abci.log"));
305
306                if counter < ITERATIONS - 1 {
307                    assert!(
308                        read.contains(format!("file {}, before rotate\n", counter).as_str()),
309                        "expect: file {}, before rotate, read: {}",
310                        counter,
311                        read
312                    )
313                };
314                if counter > 0 {
315                    assert!(
316                        read.contains(format!("file {}, after rotate\n", counter).as_str()),
317                        "expect: file {}, after rotate, read: {}",
318                        counter,
319                        read
320                    )
321                }
322
323                counter += 1;
324            });
325        assert_eq!(counter, ITERATIONS + 1);
326    }
327}