picodata_plugin/log/
mod.rs

1//! Log module provides special log marcos for end-to-end logging and ability to change
2//! default tarantool-logger templates (using `tarolog` lib).
3
4pub use log as rs_log;
5
6pub use tarolog::set_default_logger_format;
7pub use tarolog::Format;
8pub use tarolog::JsonInjector;
9pub use tarolog::PlainInjector;
10
11pub use crate::pico_debug as debug;
12pub use crate::pico_error as error;
13pub use crate::pico_info as info;
14pub use crate::pico_warn as warn;
15
16pub trait RequestIdOwner {
17    fn request_id(&self) -> &str;
18}
19
20#[macro_export]
21macro_rules! pico_error {
22        (ctx: $ctx:expr, target: $target:expr, $fmt:expr, $($arg:tt)*) => {
23            $crate::log::rs_log::error!(target: $target, concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
24        };
25        (ctx: $ctx:expr, $fmt:expr, $($arg:tt)*) => {
26            $crate::log::rs_log::error!(concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
27        };
28        (target: $target:expr, $($arg:tt)+) => {
29            $crate::log::rs_log::error!(target: $target, $($arg)+)
30        };
31        ($($arg:tt)+) => {
32            $crate::log::rs_log::error!($($arg)+)
33        };
34    }
35
36#[macro_export]
37macro_rules! pico_warn {
38        (ctx: $ctx:expr, target: $target:expr, $fmt:expr, $($arg:tt)*) => {
39            $crate::log::rs_log::warn!(target: $target, concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
40        };
41        (ctx: $ctx:expr, $fmt:expr, $($arg:tt)*) => {
42            $crate::log::rs_log::warn!(concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
43        };
44        (target: $target:expr, $($arg:tt)+) => {
45            $crate::log::rs_log::warn!(target: $target, $($arg)+)
46        };
47        ($($arg:tt)+) => {
48            $crate::log::rs_log::warn!($($arg)+)
49        };
50    }
51
52#[macro_export]
53macro_rules! pico_info {
54        (ctx: $ctx:expr, target: $target:expr, $fmt:expr, $($arg:tt)*) => {
55            $crate::log::rs_log::info!(target: $target, concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
56        };
57        (ctx: $ctx:expr, $fmt:expr, $($arg:tt)*) => {
58            $crate::log::rs_log::info!(concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
59        };
60        (target: $target:expr, $($arg:tt)+) => {
61            $crate::log::rs_log::info!(target: $target, $($arg)+)
62        };
63        ($($arg:tt)+) => {
64            $crate::log::rs_log::info!($($arg)+)
65        };
66    }
67
68#[macro_export]
69macro_rules! pico_debug {
70        (ctx: $ctx:expr, target: $target:expr, $fmt:expr, $($arg:tt)*) => {
71            $crate::log::rs_log::debug!(target: $target, concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
72        };
73        (ctx: $ctx:expr, $fmt:expr, $($arg:tt)*) => {
74            $crate::log::rs_log::debug!(concat!("[{}]: ", $fmt), $crate::log::RequestIdOwner::request_id($ctx), $($arg)*)
75        };
76        (target: $target:expr, $($arg:tt)+) => {
77            $crate::log::rs_log::debug!(target: $target, $($arg)+)
78        };
79        ($($arg:tt)+) => {
80            $crate::log::rs_log::debug!($($arg)+)
81        };
82    }
83
84#[cfg(test)]
85mod test {
86    use crate::log::RequestIdOwner;
87    use log::{Level, LevelFilter, Log, Metadata, Record};
88    use std::sync::Mutex;
89    use std::sync::OnceLock;
90
91    struct BufferedLogger {
92        buff: Mutex<Vec<(Level, String, String)>>,
93    }
94
95    impl Log for BufferedLogger {
96        fn enabled(&self, _metadata: &Metadata) -> bool {
97            true
98        }
99
100        fn log(&self, record: &Record) {
101            self.buff.lock().unwrap().push((
102                record.level(),
103                record.target().to_string(),
104                record.args().to_string(),
105            ))
106        }
107
108        fn flush(&self) {
109            self.buff.lock().unwrap().clear();
110        }
111    }
112
113    struct TestContext {
114        rid: &'static str,
115    }
116
117    impl RequestIdOwner for TestContext {
118        fn request_id(&self) -> &str {
119            self.rid
120        }
121    }
122
123    static LOGGER: OnceLock<BufferedLogger> = OnceLock::new();
124
125    fn logger() -> &'static BufferedLogger {
126        LOGGER.get_or_init(|| BufferedLogger {
127            buff: Mutex::default(),
128        })
129    }
130
131    #[test]
132    fn test_logger() {
133        log::set_logger(logger())
134            .map(|()| log::set_max_level(LevelFilter::Debug))
135            .unwrap();
136
137        test_logger_simple();
138        test_logger_with_custom_target();
139        test_logger_with_request_id();
140        test_logger_with_custom_target_and_request_id();
141    }
142
143    fn test_logger_simple() {
144        logger().flush();
145
146        pico_debug!("simple log record {}", 1);
147        pico_info!("simple log record {}", 2);
148        pico_warn!("simple log record {}", 3);
149        pico_error!("simple log record {}", 4);
150
151        assert_eq!(
152            &[
153                (
154                    Level::Debug,
155                    "picodata_plugin::log::test".to_string(),
156                    "simple log record 1".to_string()
157                ),
158                (
159                    Level::Info,
160                    "picodata_plugin::log::test".to_string(),
161                    "simple log record 2".to_string()
162                ),
163                (
164                    Level::Warn,
165                    "picodata_plugin::log::test".to_string(),
166                    "simple log record 3".to_string()
167                ),
168                (
169                    Level::Error,
170                    "picodata_plugin::log::test".to_string(),
171                    "simple log record 4".to_string()
172                ),
173            ],
174            logger().buff.lock().unwrap().as_slice()
175        );
176    }
177
178    fn test_logger_with_custom_target() {
179        logger().flush();
180
181        pico_debug!(target: "test", "log record");
182        pico_info!(target: "test","log record");
183        pico_warn!(target: "test","log record");
184        pico_error!(target: "test", "log record");
185
186        assert_eq!(
187            &[
188                (Level::Debug, "test".to_string(), "log record".to_string()),
189                (Level::Info, "test".to_string(), "log record".to_string()),
190                (Level::Warn, "test".to_string(), "log record".to_string()),
191                (Level::Error, "test".to_string(), "log record".to_string()),
192            ],
193            logger().buff.lock().unwrap().as_slice()
194        );
195    }
196
197    fn test_logger_with_request_id() {
198        logger().flush();
199
200        let ctx = TestContext { rid: "12345" };
201
202        pico_debug!(ctx: &ctx, "{}", "log record");
203        pico_info!(ctx: &ctx, "{}", "log record");
204        pico_warn!(ctx: &ctx, "{}", "log record");
205        pico_error!(ctx: &ctx, "{}", "log record");
206
207        assert_eq!(
208            &[
209                (
210                    Level::Debug,
211                    "picodata_plugin::log::test".to_string(),
212                    "[12345]: log record".to_string()
213                ),
214                (
215                    Level::Info,
216                    "picodata_plugin::log::test".to_string(),
217                    "[12345]: log record".to_string()
218                ),
219                (
220                    Level::Warn,
221                    "picodata_plugin::log::test".to_string(),
222                    "[12345]: log record".to_string()
223                ),
224                (
225                    Level::Error,
226                    "picodata_plugin::log::test".to_string(),
227                    "[12345]: log record".to_string()
228                ),
229            ],
230            logger().buff.lock().unwrap().as_slice()
231        );
232    }
233
234    fn test_logger_with_custom_target_and_request_id() {
235        logger().flush();
236
237        let ctx = TestContext { rid: "12345" };
238
239        pico_debug!(ctx: &ctx, target: "test", "{}", "log record");
240        pico_info!(ctx: &ctx, target: "test", "{}", "log record");
241        pico_warn!(ctx: &ctx, target: "test", "{}", "log record");
242        pico_error!(ctx: &ctx, target: "test", "{}", "log record");
243
244        assert_eq!(
245            &[
246                (
247                    Level::Debug,
248                    "test".to_string(),
249                    "[12345]: log record".to_string()
250                ),
251                (
252                    Level::Info,
253                    "test".to_string(),
254                    "[12345]: log record".to_string()
255                ),
256                (
257                    Level::Warn,
258                    "test".to_string(),
259                    "[12345]: log record".to_string()
260                ),
261                (
262                    Level::Error,
263                    "test".to_string(),
264                    "[12345]: log record".to_string()
265                ),
266            ],
267            logger().buff.lock().unwrap().as_slice()
268        );
269    }
270}