shors/builtin/
log.rs

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