filter.rs

  1use std::{
  2    collections::{HashMap, VecDeque},
  3    sync::{
  4        OnceLock, RwLock,
  5        atomic::{AtomicU8, Ordering},
  6    },
  7    usize,
  8};
  9
 10use crate::{SCOPE_DEPTH_MAX, SCOPE_STRING_SEP_STR, Scope, ScopeAlloc, env_config};
 11
 12use log;
 13
 14static ENV_FILTER: OnceLock<env_config::EnvFilter> = OnceLock::new();
 15static SCOPE_MAP: RwLock<Option<ScopeMap>> = RwLock::new(None);
 16
 17pub const LEVEL_ENABLED_MAX_DEFAULT: log::LevelFilter = log::LevelFilter::Info;
 18/// The maximum log level of verbosity that is enabled by default.
 19/// All messages more verbose than this level will be discarded
 20/// by default unless specially configured.
 21///
 22/// This is used instead of the `log::max_level` as we need to tell the `log`
 23/// crate that the max level is everything, so that we can dynamically enable
 24/// logs that are more verbose than this level without the `log` crate throwing
 25/// them away before we see them
 26static mut LEVEL_ENABLED_MAX_STATIC: log::LevelFilter = LEVEL_ENABLED_MAX_DEFAULT;
 27
 28/// A cache of the true maximum log level that _could_ be printed. This is based
 29/// on the maximally verbose level that is configured by the user, and is used
 30/// to filter out logs more verbose than any configured level.
 31///
 32/// E.g. if `LEVEL_ENABLED_MAX_STATIC `is 'info' but a user has configured some
 33/// scope to print at a `debug` level, then this will be `debug`, and all
 34/// `trace` logs will be discarded.
 35/// Therefore, it should always be `>= LEVEL_ENABLED_MAX_STATIC`
 36// PERF: this doesn't need to be an atomic, we don't actually care about race conditions here
 37pub static LEVEL_ENABLED_MAX_CONFIG: AtomicU8 = AtomicU8::new(LEVEL_ENABLED_MAX_DEFAULT as u8);
 38
 39pub fn init_env_filter(filter: env_config::EnvFilter) {
 40    if let Some(level_max) = filter.level_global {
 41        unsafe { LEVEL_ENABLED_MAX_STATIC = level_max }
 42    }
 43    if ENV_FILTER.set(filter).is_err() {
 44        panic!("Environment filter cannot be initialized twice");
 45    }
 46}
 47
 48pub fn is_possibly_enabled_level(level: log::Level) -> bool {
 49    return level as u8 <= LEVEL_ENABLED_MAX_CONFIG.load(Ordering::Relaxed);
 50}
 51
 52pub fn is_scope_enabled(scope: &Scope, module_path: Option<&str>, level: log::Level) -> bool {
 53    if level <= unsafe { LEVEL_ENABLED_MAX_STATIC } {
 54        // [FAST PATH]
 55        // if the message is at or below the minimum printed log level
 56        // (where error < warn < info etc) then always enable
 57        return true;
 58    }
 59    if !is_possibly_enabled_level(level) {
 60        // [FAST PATH PT. 2]
 61        // if the message is above the maximum enabled log level
 62        // (where error < warn < info etc) then disable without checking
 63        // scope map
 64        return false;
 65    }
 66    let global_scope_map = SCOPE_MAP.read().unwrap_or_else(|err| {
 67        SCOPE_MAP.clear_poison();
 68        return err.into_inner();
 69    });
 70
 71    let Some(map) = global_scope_map.as_ref() else {
 72        // on failure, return false because it's not <= LEVEL_ENABLED_MAX_STATIC
 73        return false;
 74    };
 75
 76    if map.is_empty() {
 77        // if no scopes are enabled, return false because it's not <= LEVEL_ENABLED_MAX_STATIC
 78        return false;
 79    }
 80    let enabled_status = map.is_enabled(&scope, module_path, level);
 81    return match enabled_status {
 82        // if it isn't configured, then it it's disabled because it's not <= LEVEL_ENABLED_MAX_STATIC
 83        EnabledStatus::NotConfigured => false,
 84        EnabledStatus::Enabled => true,
 85        EnabledStatus::Disabled => false,
 86    };
 87}
 88
 89pub(crate) fn refresh() {
 90    refresh_from_settings(&HashMap::default());
 91}
 92
 93pub fn refresh_from_settings(settings: &HashMap<String, String>) {
 94    let env_config = ENV_FILTER.get();
 95    let map_new = ScopeMap::new_from_settings_and_env(settings, env_config);
 96    let mut level_enabled_max = unsafe { LEVEL_ENABLED_MAX_STATIC };
 97    for entry in &map_new.entries {
 98        if let Some(level) = entry.enabled {
 99            level_enabled_max = level_enabled_max.max(level);
100        }
101    }
102    LEVEL_ENABLED_MAX_CONFIG.store(level_enabled_max as u8, Ordering::Release);
103
104    {
105        let mut global_map = SCOPE_MAP.write().unwrap_or_else(|err| {
106            SCOPE_MAP.clear_poison();
107            err.into_inner()
108        });
109        global_map.replace(map_new);
110    }
111    log::trace!("Log configuration updated");
112}
113
114fn level_filter_from_str(level_str: &String) -> Option<log::LevelFilter> {
115    use log::LevelFilter::*;
116    let level = match level_str.to_ascii_lowercase().as_str() {
117        "" => Trace,
118        "trace" => Trace,
119        "debug" => Debug,
120        "info" => Info,
121        "warn" => Warn,
122        "error" => Error,
123        "off" => Off,
124        "disable" | "no" | "none" | "disabled" => {
125            crate::warn!(
126                "Invalid log level \"{level_str}\", to disable logging set to \"off\". Defaulting to \"off\"."
127            );
128            Off
129        }
130        _ => {
131            crate::warn!("Invalid log level \"{level_str}\", ignoring");
132            return None;
133        }
134    };
135    return Some(level);
136}
137
138fn scope_alloc_from_scope_str(scope_str: &String) -> Option<ScopeAlloc> {
139    let mut scope_buf = [""; SCOPE_DEPTH_MAX];
140    let mut index = 0;
141    let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR);
142    while index < SCOPE_DEPTH_MAX {
143        let Some(scope) = scope_iter.next() else {
144            break;
145        };
146        if scope == "" {
147            continue;
148        }
149        scope_buf[index] = scope;
150        index += 1;
151    }
152    if index == 0 {
153        return None;
154    }
155    if let Some(_) = scope_iter.next() {
156        crate::warn!(
157            "Invalid scope key, too many nested scopes: '{scope_str}'. Max depth is {SCOPE_DEPTH_MAX}",
158        );
159        return None;
160    }
161    let scope = scope_buf.map(|s| s.to_string());
162    return Some(scope);
163}
164
165#[derive(PartialEq, Eq)]
166pub struct ScopeMap {
167    entries: Vec<ScopeMapEntry>,
168    modules: Vec<(String, log::LevelFilter)>,
169    root_count: usize,
170}
171
172#[derive(PartialEq, Eq)]
173pub struct ScopeMapEntry {
174    scope: String,
175    enabled: Option<log::LevelFilter>,
176    descendants: std::ops::Range<usize>,
177}
178
179#[derive(Debug, Clone, Copy, PartialEq, Eq)]
180pub enum EnabledStatus {
181    Enabled,
182    Disabled,
183    NotConfigured,
184}
185
186impl ScopeMap {
187    pub fn new_from_settings_and_env(
188        items_input_map: &HashMap<String, String>,
189        env_config: Option<&env_config::EnvFilter>,
190    ) -> Self {
191        let mut items = Vec::with_capacity(
192            items_input_map.len() + env_config.map_or(0, |c| c.directive_names.len()),
193        );
194        let mut modules = Vec::with_capacity(4);
195
196        if let Some(env_filter) = env_config {
197            // TODO: parse on load instead of every reload
198            items.extend(
199                env_filter
200                    .directive_names
201                    .iter()
202                    .zip(env_filter.directive_levels.iter())
203                    .filter_map(|(scope_str, &level_filter)| {
204                        if items_input_map.get(scope_str).is_some() {
205                            return None;
206                        }
207                        if scope_str.contains("::") {
208                            modules.push((scope_str.clone(), level_filter));
209                            return None;
210                        }
211                        let scope = scope_alloc_from_scope_str(scope_str)?;
212
213                        Some((scope, level_filter))
214                    }),
215            );
216        }
217        items.extend(
218            items_input_map
219                .into_iter()
220                .filter_map(|(scope_str, level_str)| {
221                    if scope_str.contains("::") {
222                        modules.push((scope_str.clone(), level_str.parse().ok()?));
223                        return None;
224                    }
225                    let level_filter = level_filter_from_str(&level_str)?;
226                    let scope = scope_alloc_from_scope_str(&scope_str)?;
227                    return Some((scope, level_filter));
228                }),
229        );
230
231        items.sort_by(|a, b| a.0.cmp(&b.0));
232        modules.sort_by(|(a_name, _), (b_name, _)| a_name.cmp(b_name));
233
234        let mut this = Self {
235            entries: Vec::with_capacity(items.len() * SCOPE_DEPTH_MAX),
236            modules,
237            root_count: 0,
238        };
239
240        let items_count = items.len();
241
242        struct ProcessQueueEntry {
243            parent_index: usize,
244            depth: usize,
245            items_range: std::ops::Range<usize>,
246        }
247        let mut process_queue = VecDeque::new();
248        process_queue.push_back(ProcessQueueEntry {
249            parent_index: usize::MAX,
250            depth: 0,
251            items_range: 0..items_count,
252        });
253
254        let empty_range = 0..0;
255
256        while let Some(process_entry) = process_queue.pop_front() {
257            let ProcessQueueEntry {
258                items_range,
259                depth,
260                parent_index,
261            } = process_entry;
262            let mut cursor = items_range.start;
263            let res_entries_start = this.entries.len();
264            while cursor < items_range.end {
265                let sub_items_start = cursor;
266                cursor += 1;
267                let scope_name = &items[sub_items_start].0[depth];
268                while cursor < items_range.end && &items[cursor].0[depth] == scope_name {
269                    cursor += 1;
270                }
271                let sub_items_end = cursor;
272                if scope_name == "" {
273                    assert_eq!(sub_items_start + 1, sub_items_end);
274                    assert_ne!(depth, 0);
275                    assert_ne!(parent_index, usize::MAX);
276                    assert!(this.entries[parent_index].enabled.is_none());
277                    this.entries[parent_index].enabled = Some(items[sub_items_start].1);
278                    continue;
279                }
280                let is_valid_scope = scope_name != "";
281                let is_last = depth + 1 == SCOPE_DEPTH_MAX || !is_valid_scope;
282                let mut enabled = None;
283                if is_last {
284                    assert_eq!(
285                        sub_items_start + 1,
286                        sub_items_end,
287                        "Expected one item: got: {:?}",
288                        &items[items_range.clone()]
289                    );
290                    enabled = Some(items[sub_items_start].1);
291                } else {
292                    let entry_index = this.entries.len();
293                    process_queue.push_back(ProcessQueueEntry {
294                        items_range: sub_items_start..sub_items_end,
295                        parent_index: entry_index,
296                        depth: depth + 1,
297                    });
298                }
299                this.entries.push(ScopeMapEntry {
300                    scope: scope_name.to_owned(),
301                    enabled,
302                    descendants: empty_range.clone(),
303                });
304            }
305            let res_entries_end = this.entries.len();
306            if parent_index != usize::MAX {
307                this.entries[parent_index].descendants = res_entries_start..res_entries_end;
308            } else {
309                this.root_count = res_entries_end;
310            }
311        }
312
313        return this;
314    }
315
316    pub fn is_empty(&self) -> bool {
317        self.entries.is_empty() && self.modules.is_empty()
318    }
319
320    pub fn is_enabled<S>(
321        &self,
322        scope: &[S; SCOPE_DEPTH_MAX],
323        module_path: Option<&str>,
324        level: log::Level,
325    ) -> EnabledStatus
326    where
327        S: AsRef<str>,
328    {
329        let mut enabled = None;
330        let mut cur_range = &self.entries[0..self.root_count];
331        let mut depth = 0;
332
333        'search: while !cur_range.is_empty()
334            && depth < SCOPE_DEPTH_MAX
335            && scope[depth].as_ref() != ""
336        {
337            for entry in cur_range {
338                if entry.scope == scope[depth].as_ref() {
339                    enabled = entry.enabled.or(enabled);
340                    cur_range = &self.entries[entry.descendants.clone()];
341                    depth += 1;
342                    continue 'search;
343                }
344            }
345            break 'search;
346        }
347
348        if enabled.is_none() && !self.modules.is_empty() && module_path.is_some() {
349            let module_path = module_path.unwrap();
350            for (module, filter) in &self.modules {
351                if module == module_path {
352                    enabled.replace(*filter);
353                    break;
354                }
355            }
356        }
357
358        if let Some(enabled_filter) = enabled {
359            if level <= enabled_filter {
360                return EnabledStatus::Enabled;
361            }
362            return EnabledStatus::Disabled;
363        }
364        return EnabledStatus::NotConfigured;
365    }
366}
367
368#[cfg(test)]
369mod tests {
370    use crate::private::scope_new;
371
372    use super::*;
373
374    fn scope_map_from_keys(kv: &[(&str, &str)]) -> ScopeMap {
375        let hash_map: HashMap<String, String> = kv
376            .iter()
377            .map(|(k, v)| (k.to_string(), v.to_string()))
378            .collect();
379        ScopeMap::new_from_settings_and_env(&hash_map, None)
380    }
381
382    #[test]
383    fn test_initialization() {
384        let map = scope_map_from_keys(&[("a.b.c.d", "trace")]);
385        assert_eq!(map.root_count, 1);
386        assert_eq!(map.entries.len(), 4);
387
388        let map = scope_map_from_keys(&[]);
389        assert_eq!(map.root_count, 0);
390        assert_eq!(map.entries.len(), 0);
391
392        let map = scope_map_from_keys(&[("", "trace")]);
393        assert_eq!(map.root_count, 0);
394        assert_eq!(map.entries.len(), 0);
395
396        let map = scope_map_from_keys(&[("foo..bar", "trace")]);
397        assert_eq!(map.root_count, 1);
398        assert_eq!(map.entries.len(), 2);
399
400        let map = scope_map_from_keys(&[
401            ("a.b.c.d", "trace"),
402            ("e.f.g.h", "debug"),
403            ("i.j.k.l", "info"),
404            ("m.n.o.p", "warn"),
405            ("q.r.s.t", "error"),
406        ]);
407        assert_eq!(map.root_count, 5);
408        assert_eq!(map.entries.len(), 20);
409        assert_eq!(map.entries[0].scope, "a");
410        assert_eq!(map.entries[1].scope, "e");
411        assert_eq!(map.entries[2].scope, "i");
412        assert_eq!(map.entries[3].scope, "m");
413        assert_eq!(map.entries[4].scope, "q");
414    }
415
416    fn scope_from_scope_str(scope_str: &'static str) -> Scope {
417        let mut scope_buf = [""; SCOPE_DEPTH_MAX];
418        let mut index = 0;
419        let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR);
420        while index < SCOPE_DEPTH_MAX {
421            let Some(scope) = scope_iter.next() else {
422                break;
423            };
424            if scope == "" {
425                continue;
426            }
427            scope_buf[index] = scope;
428            index += 1;
429        }
430        assert_ne!(index, 0);
431        assert!(scope_iter.next().is_none());
432        return scope_buf;
433    }
434
435    #[test]
436    fn test_is_enabled() {
437        let map = scope_map_from_keys(&[
438            ("a.b.c.d", "trace"),
439            ("e.f.g.h", "debug"),
440            ("i.j.k.l", "info"),
441            ("m.n.o.p", "warn"),
442            ("q.r.s.t", "error"),
443        ]);
444        use log::Level;
445        assert_eq!(
446            map.is_enabled(&scope_from_scope_str("a.b.c.d"), None, Level::Trace),
447            EnabledStatus::Enabled
448        );
449        assert_eq!(
450            map.is_enabled(&scope_from_scope_str("a.b.c.d"), None, Level::Debug),
451            EnabledStatus::Enabled
452        );
453
454        assert_eq!(
455            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Debug),
456            EnabledStatus::Enabled
457        );
458        assert_eq!(
459            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Info),
460            EnabledStatus::Enabled
461        );
462        assert_eq!(
463            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Trace),
464            EnabledStatus::Disabled
465        );
466
467        assert_eq!(
468            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Info),
469            EnabledStatus::Enabled
470        );
471        assert_eq!(
472            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Warn),
473            EnabledStatus::Enabled
474        );
475        assert_eq!(
476            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Debug),
477            EnabledStatus::Disabled
478        );
479
480        assert_eq!(
481            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Warn),
482            EnabledStatus::Enabled
483        );
484        assert_eq!(
485            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Error),
486            EnabledStatus::Enabled
487        );
488        assert_eq!(
489            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Info),
490            EnabledStatus::Disabled
491        );
492
493        assert_eq!(
494            map.is_enabled(&scope_from_scope_str("q.r.s.t"), None, Level::Error),
495            EnabledStatus::Enabled
496        );
497        assert_eq!(
498            map.is_enabled(&scope_from_scope_str("q.r.s.t"), None, Level::Warn),
499            EnabledStatus::Disabled
500        );
501    }
502
503    #[test]
504    fn test_is_enabled_module() {
505        let mut map = scope_map_from_keys(&[("a", "trace")]);
506        map.modules = [("a::b::c", "trace"), ("a::b::d", "debug")]
507            .map(|(k, v)| (k.to_string(), v.parse().unwrap()))
508            .to_vec();
509        use log::Level;
510        assert_eq!(
511            map.is_enabled(
512                &scope_from_scope_str("__unused__"),
513                Some("a::b::c"),
514                Level::Trace
515            ),
516            EnabledStatus::Enabled
517        );
518        assert_eq!(
519            map.is_enabled(
520                &scope_from_scope_str("__unused__"),
521                Some("a::b::d"),
522                Level::Debug
523            ),
524            EnabledStatus::Enabled
525        );
526        assert_eq!(
527            map.is_enabled(
528                &scope_from_scope_str("__unused__"),
529                Some("a::b::d"),
530                Level::Trace,
531            ),
532            EnabledStatus::Disabled
533        );
534        assert_eq!(
535            map.is_enabled(
536                &scope_from_scope_str("__unused__"),
537                Some("a::e"),
538                Level::Info
539            ),
540            EnabledStatus::NotConfigured
541        );
542        assert_eq!(
543            map.is_enabled(&scope_from_scope_str("a"), Some("a::b::d"), Level::Trace),
544            EnabledStatus::Enabled,
545        );
546    }
547
548    fn scope_map_from_keys_and_env(kv: &[(&str, &str)], env: &env_config::EnvFilter) -> ScopeMap {
549        let hash_map: HashMap<String, String> = kv
550            .iter()
551            .map(|(k, v)| (k.to_string(), v.to_string()))
552            .collect();
553        ScopeMap::new_from_settings_and_env(&hash_map, Some(env))
554    }
555
556    #[test]
557    fn test_initialization_with_env() {
558        let env_filter = env_config::parse("a.b=debug,u=error").unwrap();
559        let map = scope_map_from_keys_and_env(&[], &env_filter);
560        assert_eq!(map.root_count, 2);
561        assert_eq!(map.entries.len(), 3);
562        assert_eq!(
563            map.is_enabled(&scope_new(&["a"]), None, log::Level::Debug),
564            EnabledStatus::NotConfigured
565        );
566        assert_eq!(
567            map.is_enabled(&scope_new(&["a", "b"]), None, log::Level::Debug),
568            EnabledStatus::Enabled
569        );
570        assert_eq!(
571            map.is_enabled(&scope_new(&["a", "b", "c"]), None, log::Level::Trace),
572            EnabledStatus::Disabled
573        );
574
575        let env_filter = env_config::parse("a.b=debug,e.f.g.h=trace,u=error").unwrap();
576        let map = scope_map_from_keys_and_env(
577            &[
578                ("a.b.c.d", "trace"),
579                ("e.f.g.h", "debug"),
580                ("i.j.k.l", "info"),
581                ("m.n.o.p", "warn"),
582                ("q.r.s.t", "error"),
583            ],
584            &env_filter,
585        );
586        assert_eq!(map.root_count, 6);
587        assert_eq!(map.entries.len(), 21);
588        assert_eq!(map.entries[0].scope, "a");
589        assert_eq!(map.entries[1].scope, "e");
590        assert_eq!(map.entries[2].scope, "i");
591        assert_eq!(map.entries[3].scope, "m");
592        assert_eq!(map.entries[4].scope, "q");
593        assert_eq!(map.entries[5].scope, "u");
594        assert_eq!(
595            map.is_enabled(&scope_new(&["a", "b", "c", "d"]), None, log::Level::Trace),
596            EnabledStatus::Enabled
597        );
598        assert_eq!(
599            map.is_enabled(&scope_new(&["a", "b", "c"]), None, log::Level::Trace),
600            EnabledStatus::Disabled
601        );
602        assert_eq!(
603            map.is_enabled(&scope_new(&["u", "v"]), None, log::Level::Warn),
604            EnabledStatus::Disabled
605        );
606        // settings override env
607        assert_eq!(
608            map.is_enabled(&scope_new(&["e", "f", "g", "h"]), None, log::Level::Trace),
609            EnabledStatus::Disabled,
610        );
611    }
612}