zlog: Fix dynamic mod path filtering (#44296)

Ben Kunkle created

Closes #ISSUE

Release Notes:

- Linux: cleaned up noisy logs from `zbus`

Change summary

crates/zlog/src/filter.rs | 30 +++++++++++++++++++-----------
crates/zlog/src/sink.rs   |  6 +++---
crates/zlog/src/zlog.rs   | 20 ++++++++++++++------
3 files changed, 36 insertions(+), 20 deletions(-)

Detailed changes

crates/zlog/src/filter.rs 🔗

@@ -5,12 +5,12 @@ use std::sync::{
     atomic::{AtomicU8, Ordering},
 };
 
-use crate::{SCOPE_DEPTH_MAX, SCOPE_STRING_SEP_STR, Scope, ScopeAlloc, env_config, private};
+use crate::{SCOPE_DEPTH_MAX, SCOPE_STRING_SEP_STR, ScopeAlloc, ScopeRef, env_config, private};
 
 use log;
 
 static ENV_FILTER: OnceLock<env_config::EnvFilter> = OnceLock::new();
-static SCOPE_MAP: RwLock<Option<ScopeMap>> = RwLock::new(None);
+static SCOPE_MAP: RwLock<ScopeMap> = RwLock::new(ScopeMap::empty());
 
 pub const LEVEL_ENABLED_MAX_DEFAULT: log::LevelFilter = log::LevelFilter::Info;
 /// The maximum log level of verbosity that is enabled by default.
@@ -59,7 +59,11 @@ pub fn is_possibly_enabled_level(level: log::Level) -> bool {
     level as u8 <= LEVEL_ENABLED_MAX_CONFIG.load(Ordering::Acquire)
 }
 
-pub fn is_scope_enabled(scope: &Scope, module_path: Option<&str>, level: log::Level) -> bool {
+pub fn is_scope_enabled(
+    scope: &ScopeRef<'_>,
+    module_path: Option<&str>,
+    level: log::Level,
+) -> bool {
     // TODO: is_always_allowed_level that checks against LEVEL_ENABLED_MIN_CONFIG
     if !is_possibly_enabled_level(level) {
         // [FAST PATH]
@@ -74,16 +78,11 @@ pub fn is_scope_enabled(scope: &Scope, module_path: Option<&str>, level: log::Le
         err.into_inner()
     });
 
-    let Some(map) = global_scope_map.as_ref() else {
-        // on failure, return false because it's not <= LEVEL_ENABLED_MAX_STATIC
-        return is_enabled_by_default;
-    };
-
-    if map.is_empty() {
+    if global_scope_map.is_empty() {
         // if no scopes are enabled, return false because it's not <= LEVEL_ENABLED_MAX_STATIC
         return is_enabled_by_default;
     }
-    let enabled_status = map.is_enabled(scope, module_path, level);
+    let enabled_status = global_scope_map.is_enabled(scope, module_path, level);
     match enabled_status {
         EnabledStatus::NotConfigured => is_enabled_by_default,
         EnabledStatus::Enabled => true,
@@ -107,7 +106,7 @@ pub fn refresh_from_settings(settings: &HashMap<String, String>) {
             SCOPE_MAP.clear_poison();
             err.into_inner()
         });
-        global_map.replace(map_new);
+        *global_map = map_new;
     }
     log::trace!("Log configuration updated");
 }
@@ -395,12 +394,21 @@ impl ScopeMap {
         }
         EnabledStatus::NotConfigured
     }
+
+    const fn empty() -> ScopeMap {
+        ScopeMap {
+            entries: vec![],
+            modules: vec![],
+            root_count: 0,
+        }
+    }
 }
 
 #[cfg(test)]
 mod tests {
     use log::LevelFilter;
 
+    use crate::Scope;
     use crate::private::scope_new;
 
     use super::*;

crates/zlog/src/sink.rs 🔗

@@ -8,7 +8,7 @@ use std::{
     },
 };
 
-use crate::{SCOPE_STRING_SEP_CHAR, Scope};
+use crate::{SCOPE_STRING_SEP_CHAR, ScopeRef};
 
 // ANSI color escape codes for log levels
 const ANSI_RESET: &str = "\x1b[0m";
@@ -35,7 +35,7 @@ static SINK_FILE_SIZE_BYTES: AtomicU64 = AtomicU64::new(0);
 const SINK_FILE_SIZE_BYTES_MAX: u64 = 1024 * 1024; // 1 MB
 
 pub struct Record<'a> {
-    pub scope: Scope,
+    pub scope: ScopeRef<'a>,
     pub level: log::Level,
     pub message: &'a std::fmt::Arguments<'a>,
     pub module_path: Option<&'a str>,
@@ -208,7 +208,7 @@ pub fn flush() {
 }
 
 struct SourceFmt<'a> {
-    scope: Scope,
+    scope: ScopeRef<'a>,
     module_path: Option<&'a str>,
     line: Option<u32>,
     ansi: bool,

crates/zlog/src/zlog.rs 🔗

@@ -70,15 +70,18 @@ impl log::Log for Zlog {
         if !self.enabled(record.metadata()) {
             return;
         }
-        let (crate_name_scope, module_scope) = match record.module_path_static() {
+        let module_path = record.module_path().or(record.file());
+        let (crate_name_scope, module_scope) = match module_path {
             Some(module_path) => {
                 let crate_name = private::extract_crate_name_from_module_path(module_path);
-                let crate_name_scope = private::scope_new(&[crate_name]);
-                let module_scope = private::scope_new(&[module_path]);
+                let crate_name_scope = private::scope_ref_new(&[crate_name]);
+                let module_scope = private::scope_ref_new(&[module_path]);
                 (crate_name_scope, module_scope)
             }
-            // TODO: when do we hit this
-            None => (private::scope_new(&[]), private::scope_new(&["*unknown*"])),
+            None => {
+                // TODO: when do we hit this
+                (private::scope_new(&[]), private::scope_new(&["*unknown*"]))
+            }
         };
         let level = record.metadata().level();
         if !filter::is_scope_enabled(&crate_name_scope, Some(record.target()), level) {
@@ -89,7 +92,7 @@ impl log::Log for Zlog {
             level,
             message: record.args(),
             // PERF(batching): store non-static paths in a cache + leak them and pass static str here
-            module_path: record.module_path().or(record.file()),
+            module_path,
             line: record.line(),
         });
     }
@@ -252,6 +255,10 @@ pub mod private {
     }
 
     pub const fn scope_new(scopes: &[&'static str]) -> Scope {
+        scope_ref_new(scopes)
+    }
+
+    pub const fn scope_ref_new<'a>(scopes: &[&'a str]) -> ScopeRef<'a> {
         assert!(scopes.len() <= SCOPE_DEPTH_MAX);
         let mut scope = [""; SCOPE_DEPTH_MAX];
         let mut i = 0;
@@ -275,6 +282,7 @@ pub mod private {
 }
 
 pub type Scope = [&'static str; SCOPE_DEPTH_MAX];
+pub type ScopeRef<'a> = [&'a str; SCOPE_DEPTH_MAX];
 pub type ScopeAlloc = [String; SCOPE_DEPTH_MAX];
 const SCOPE_STRING_SEP_STR: &str = ".";
 const SCOPE_STRING_SEP_CHAR: char = '.';