1//! # logger
2pub use log as log_impl;
3
4mod env_config;
5pub mod filter;
6pub mod sink;
7
8pub use sink::{flush, init_output_file, init_output_stderr, init_output_stdout};
9
10pub const SCOPE_DEPTH_MAX: usize = 4;
11
12pub fn init() {
13 if let Err(err) = try_init() {
14 log::error!("{err}");
15 eprintln!("{err}");
16 }
17}
18
19pub fn try_init() -> anyhow::Result<()> {
20 log::set_logger(&ZLOG)?;
21 log::set_max_level(log::LevelFilter::max());
22 process_env();
23 filter::refresh_from_settings(&std::collections::HashMap::default());
24 Ok(())
25}
26
27pub fn init_test() {
28 if get_env_config().is_some() && try_init().is_ok() {
29 init_output_stdout();
30 }
31}
32
33fn get_env_config() -> Option<String> {
34 std::env::var("ZED_LOG")
35 .or_else(|_| std::env::var("RUST_LOG"))
36 .ok()
37}
38
39pub fn process_env() {
40 let Some(env_config) = get_env_config() else {
41 return;
42 };
43 match env_config::parse(&env_config) {
44 Ok(filter) => {
45 filter::init_env_filter(filter);
46 }
47 Err(err) => {
48 eprintln!("Failed to parse log filter: {}", err);
49 }
50 }
51}
52
53static ZLOG: Zlog = Zlog {};
54
55pub struct Zlog {}
56
57impl log::Log for Zlog {
58 fn enabled(&self, metadata: &log::Metadata) -> bool {
59 filter::is_possibly_enabled_level(metadata.level())
60 }
61
62 fn log(&self, record: &log::Record) {
63 if !self.enabled(record.metadata()) {
64 return;
65 }
66 let (crate_name_scope, module_scope) = match record.module_path_static() {
67 Some(module_path) => {
68 let crate_name = private::extract_crate_name_from_module_path(module_path);
69 let crate_name_scope = private::scope_new(&[crate_name]);
70 let module_scope = private::scope_new(&[module_path]);
71 (crate_name_scope, module_scope)
72 }
73 // TODO: when do we hit this
74 None => (private::scope_new(&[]), private::scope_new(&["*unknown*"])),
75 };
76 let level = record.metadata().level();
77 if !filter::is_scope_enabled(&crate_name_scope, record.module_path(), level) {
78 return;
79 }
80 sink::submit(sink::Record {
81 scope: module_scope,
82 level,
83 message: record.args(),
84 // PERF(batching): store non-static paths in a cache + leak them and pass static str here
85 module_path: record.module_path().or(record.file()),
86 });
87 }
88
89 fn flush(&self) {
90 sink::flush();
91 }
92}
93
94#[macro_export]
95macro_rules! log {
96 ($logger:expr, $level:expr, $($arg:tt)+) => {
97 let level = $level;
98 let logger = $logger;
99 let enabled = $crate::filter::is_scope_enabled(&logger.scope, Some(module_path!()), level);
100 if enabled {
101 $crate::sink::submit($crate::sink::Record {
102 scope: logger.scope,
103 level,
104 message: &format_args!($($arg)+),
105 module_path: Some(module_path!()),
106 });
107 }
108 }
109}
110
111#[macro_export]
112macro_rules! trace {
113 ($logger:expr => $($arg:tt)+) => {
114 $crate::log!($logger, $crate::log_impl::Level::Trace, $($arg)+);
115 };
116 ($($arg:tt)+) => {
117 $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Trace, $($arg)+);
118 };
119}
120
121#[macro_export]
122macro_rules! debug {
123 ($logger:expr => $($arg:tt)+) => {
124 $crate::log!($logger, $crate::log_impl::Level::Debug, $($arg)+);
125 };
126 ($($arg:tt)+) => {
127 $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Debug, $($arg)+);
128 };
129}
130
131#[macro_export]
132macro_rules! info {
133 ($logger:expr => $($arg:tt)+) => {
134 $crate::log!($logger, $crate::log_impl::Level::Info, $($arg)+);
135 };
136 ($($arg:tt)+) => {
137 $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Info, $($arg)+);
138 };
139}
140
141#[macro_export]
142macro_rules! warn {
143 ($logger:expr => $($arg:tt)+) => {
144 $crate::log!($logger, $crate::log_impl::Level::Warn, $($arg)+);
145 };
146 ($($arg:tt)+) => {
147 $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Warn, $($arg)+);
148 };
149}
150
151#[macro_export]
152macro_rules! error {
153 ($logger:expr => $($arg:tt)+) => {
154 $crate::log!($logger, $crate::log_impl::Level::Error, $($arg)+);
155 };
156 ($($arg:tt)+) => {
157 $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Error, $($arg)+);
158 };
159}
160
161/// Creates a timer that logs the duration it was active for either when
162/// it is dropped, or when explicitly stopped using the `end` method.
163/// Logs at the `trace` level.
164/// Note that it will include time spent across await points
165/// (i.e. should not be used to measure the performance of async code)
166/// However, this is a feature not a bug, as it allows for a more accurate
167/// understanding of how long the action actually took to complete, including
168/// interruptions, which can help explain why something may have timed out,
169/// why it took longer to complete than it would have had the await points resolved
170/// immediately, etc.
171#[macro_export]
172macro_rules! time {
173 ($logger:expr => $name:expr) => {
174 $crate::Timer::new($logger, $name)
175 };
176 ($name:expr) => {
177 time!($crate::default_logger!() => $name)
178 };
179}
180
181#[macro_export]
182macro_rules! scoped {
183 ($parent:expr => $name:expr) => {{
184 $crate::scoped_logger($parent, $name)
185 }};
186 ($name:expr) => {
187 $crate::scoped!($crate::default_logger!() => $name)
188 };
189}
190
191pub const fn scoped_logger(parent: Logger, name: &'static str) -> Logger {
192 let mut scope = parent.scope;
193 let mut index = 1; // always have crate/module name
194 while index < scope.len() && !scope[index].is_empty() {
195 index += 1;
196 }
197 if index >= scope.len() {
198 #[cfg(debug_assertions)]
199 {
200 panic!("Scope overflow trying to add scope... ignoring scope");
201 }
202 }
203 scope[index] = name;
204 Logger { scope }
205}
206
207#[macro_export]
208macro_rules! default_logger {
209 () => {
210 $crate::Logger {
211 scope: $crate::private::scope_new(&[$crate::crate_name!()]),
212 }
213 };
214}
215
216#[macro_export]
217macro_rules! crate_name {
218 () => {
219 $crate::private::extract_crate_name_from_module_path(module_path!())
220 };
221}
222
223/// functions that are used in macros, and therefore must be public,
224/// but should not be used directly
225pub mod private {
226 use super::*;
227
228 pub const fn extract_crate_name_from_module_path(module_path: &str) -> &str {
229 let mut i = 0;
230 let mod_path_bytes = module_path.as_bytes();
231 let mut index = mod_path_bytes.len();
232 while i + 1 < mod_path_bytes.len() {
233 if mod_path_bytes[i] == b':' && mod_path_bytes[i + 1] == b':' {
234 index = i;
235 break;
236 }
237 i += 1;
238 }
239 let Some((crate_name, _)) = module_path.split_at_checked(index) else {
240 return module_path;
241 };
242 crate_name
243 }
244
245 pub const fn scope_new(scopes: &[&'static str]) -> Scope {
246 assert!(scopes.len() <= SCOPE_DEPTH_MAX);
247 let mut scope = [""; SCOPE_DEPTH_MAX];
248 let mut i = 0;
249 while i < scopes.len() {
250 scope[i] = scopes[i];
251 i += 1;
252 }
253 scope
254 }
255
256 pub fn scope_alloc_new(scopes: &[&str]) -> ScopeAlloc {
257 assert!(scopes.len() <= SCOPE_DEPTH_MAX);
258 let mut scope = [""; SCOPE_DEPTH_MAX];
259 scope[0..scopes.len()].copy_from_slice(scopes);
260 scope.map(|s| s.to_string())
261 }
262
263 pub fn scope_to_alloc(scope: &Scope) -> ScopeAlloc {
264 scope.map(|s| s.to_string())
265 }
266}
267
268pub type Scope = [&'static str; SCOPE_DEPTH_MAX];
269pub type ScopeAlloc = [String; SCOPE_DEPTH_MAX];
270const SCOPE_STRING_SEP_STR: &str = ".";
271const SCOPE_STRING_SEP_CHAR: char = '.';
272
273#[derive(Clone, Copy, Debug, PartialEq, Eq)]
274pub struct Logger {
275 pub scope: Scope,
276}
277
278impl log::Log for Logger {
279 fn enabled(&self, metadata: &log::Metadata) -> bool {
280 filter::is_possibly_enabled_level(metadata.level())
281 }
282
283 fn log(&self, record: &log::Record) {
284 if !self.enabled(record.metadata()) {
285 return;
286 }
287 let level = record.metadata().level();
288 if !filter::is_scope_enabled(&self.scope, record.module_path(), level) {
289 return;
290 }
291 sink::submit(sink::Record {
292 scope: self.scope,
293 level,
294 message: record.args(),
295 module_path: record.module_path(),
296 });
297 }
298
299 fn flush(&self) {
300 sink::flush();
301 }
302}
303
304pub struct Timer {
305 pub logger: Logger,
306 pub start_time: std::time::Instant,
307 pub name: &'static str,
308 pub warn_if_longer_than: Option<std::time::Duration>,
309 pub done: bool,
310}
311
312impl Drop for Timer {
313 fn drop(&mut self) {
314 self.finish();
315 }
316}
317
318impl Timer {
319 #[must_use = "Timer will stop when dropped, the result of this function should be saved in a variable prefixed with `_` if it should stop when dropped"]
320 pub fn new(logger: Logger, name: &'static str) -> Self {
321 Self {
322 logger,
323 name,
324 start_time: std::time::Instant::now(),
325 warn_if_longer_than: None,
326 done: false,
327 }
328 }
329
330 pub const fn warn_if_gt(mut self, warn_limit: std::time::Duration) -> Self {
331 self.warn_if_longer_than = Some(warn_limit);
332 self
333 }
334
335 pub fn end(mut self) {
336 self.finish();
337 }
338
339 fn finish(&mut self) {
340 if self.done {
341 return;
342 }
343 let elapsed = self.start_time.elapsed();
344 if let Some(warn_limit) = self.warn_if_longer_than
345 && elapsed > warn_limit
346 {
347 crate::warn!(
348 self.logger =>
349 "Timer '{}' took {:?}. Which was longer than the expected limit of {:?}",
350 self.name,
351 elapsed,
352 warn_limit
353 );
354 self.done = true;
355 return;
356 }
357 crate::trace!(
358 self.logger =>
359 "Timer '{}' finished in {:?}",
360 self.name,
361 elapsed
362 );
363 self.done = true;
364 }
365}
366
367#[cfg(test)]
368mod tests {
369 use super::*;
370
371 #[test]
372 fn test_crate_name() {
373 assert_eq!(crate_name!(), "zlog");
374 assert_eq!(
375 private::extract_crate_name_from_module_path("my_speedy_⚡️_crate::some_module"),
376 "my_speedy_⚡️_crate"
377 );
378 assert_eq!(
379 private::extract_crate_name_from_module_path("my_speedy_crate_⚡️::some_module"),
380 "my_speedy_crate_⚡️"
381 );
382 assert_eq!(
383 private::extract_crate_name_from_module_path("my_speedy_crate_:⚡️:some_module"),
384 "my_speedy_crate_:⚡️:some_module"
385 );
386 assert_eq!(
387 private::extract_crate_name_from_module_path("my_speedy_crate_::⚡️some_module"),
388 "my_speedy_crate_"
389 );
390 }
391}