diff --git a/crates/zlog/src/filter.rs b/crates/zlog/src/filter.rs index 747a3e2261..f260119300 100644 --- a/crates/zlog/src/filter.rs +++ b/crates/zlog/src/filter.rs @@ -36,6 +36,15 @@ static mut LEVEL_ENABLED_MAX_STATIC: log::LevelFilter = LEVEL_ENABLED_MAX_DEFAUL // PERF: this doesn't need to be an atomic, we don't actually care about race conditions here pub static LEVEL_ENABLED_MAX_CONFIG: AtomicU8 = AtomicU8::new(LEVEL_ENABLED_MAX_DEFAULT as u8); +const DEFAULT_FILTERS: &[(&str, log::LevelFilter)] = &[ + #[cfg(any(target_os = "linux", target_os = "freebsd"))] + ("zbus", log::LevelFilter::Off), + #[cfg(any(target_os = "linux", target_os = "freebsd"))] + ("blade_graphics::hal::resource", log::LevelFilter::Off), + #[cfg(any(target_os = "linux", target_os = "freebsd"))] + ("naga::back::spv::writer", log::LevelFilter::Off), +]; + pub fn init_env_filter(filter: env_config::EnvFilter) { if let Some(level_max) = filter.level_global { unsafe { LEVEL_ENABLED_MAX_STATIC = level_max } @@ -92,7 +101,7 @@ pub(crate) fn refresh() { pub fn refresh_from_settings(settings: &HashMap) { let env_config = ENV_FILTER.get(); - let map_new = ScopeMap::new_from_settings_and_env(settings, env_config); + let map_new = ScopeMap::new_from_settings_and_env(settings, env_config, DEFAULT_FILTERS); let mut level_enabled_max = unsafe { LEVEL_ENABLED_MAX_STATIC }; for entry in &map_new.entries { if let Some(level) = entry.enabled { @@ -111,7 +120,7 @@ pub fn refresh_from_settings(settings: &HashMap) { log::trace!("Log configuration updated"); } -fn level_filter_from_str(level_str: &String) -> Option { +fn level_filter_from_str(level_str: &str) -> Option { use log::LevelFilter::*; let level = match level_str.to_ascii_lowercase().as_str() { "" => Trace, @@ -135,7 +144,7 @@ fn level_filter_from_str(level_str: &String) -> Option { return Some(level); } -fn scope_alloc_from_scope_str(scope_str: &String) -> Option { +fn scope_alloc_from_scope_str(scope_str: &str) -> Option { let mut scope_buf = [""; SCOPE_DEPTH_MAX]; let mut index = 0; let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR); @@ -187,46 +196,57 @@ impl ScopeMap { pub fn new_from_settings_and_env( items_input_map: &HashMap, env_config: Option<&env_config::EnvFilter>, + default_filters: &[(&str, log::LevelFilter)], ) -> Self { - let mut items = Vec::with_capacity( - items_input_map.len() + env_config.map_or(0, |c| c.directive_names.len()), + let mut items = Vec::<(ScopeAlloc, log::LevelFilter)>::with_capacity( + items_input_map.len() + + env_config.map_or(0, |c| c.directive_names.len()) + + default_filters.len(), ); let mut modules = Vec::with_capacity(4); - if let Some(env_filter) = env_config { - // TODO: parse on load instead of every reload - items.extend( - env_filter - .directive_names - .iter() - .zip(env_filter.directive_levels.iter()) - .filter_map(|(scope_str, &level_filter)| { - if items_input_map.get(scope_str).is_some() { - return None; - } - if scope_str.contains("::") { - modules.push((scope_str.clone(), level_filter)); - return None; - } - let scope = scope_alloc_from_scope_str(scope_str)?; + let env_filters = env_config.iter().flat_map(|env_filter| { + env_filter + .directive_names + .iter() + .zip(env_filter.directive_levels.iter()) + .map(|(scope_str, level_filter)| (scope_str.as_str(), *level_filter)) + }); - Some((scope, level_filter)) - }), - ); + let new_filters = items_input_map + .into_iter() + .filter_map(|(scope_str, level_str)| { + let level_filter = level_filter_from_str(level_str)?; + Some((scope_str.as_str(), level_filter)) + }); + + let all_filters = default_filters + .iter() + .cloned() + .chain(env_filters) + .chain(new_filters); + + for (scope_str, level_filter) in all_filters { + if scope_str.contains("::") { + if let Some(idx) = modules.iter().position(|(module, _)| module == scope_str) { + modules[idx].1 = level_filter; + } else { + modules.push((scope_str.to_string(), level_filter)); + } + continue; + } + let Some(scope) = scope_alloc_from_scope_str(scope_str) else { + continue; + }; + if let Some(idx) = items + .iter() + .position(|(scope_existing, _)| scope_existing == &scope) + { + items[idx].1 = level_filter; + } else { + items.push((scope, level_filter)); + } } - items.extend( - items_input_map - .into_iter() - .filter_map(|(scope_str, level_str)| { - if scope_str.contains("::") { - modules.push((scope_str.clone(), level_str.parse().ok()?)); - return None; - } - let level_filter = level_filter_from_str(&level_str)?; - let scope = scope_alloc_from_scope_str(&scope_str)?; - return Some((scope, level_filter)); - }), - ); items.sort_by(|a, b| a.0.cmp(&b.0)); modules.sort_by(|(a_name, _), (b_name, _)| a_name.cmp(b_name)); @@ -376,7 +396,7 @@ mod tests { .iter() .map(|(k, v)| (k.to_string(), v.to_string())) .collect(); - ScopeMap::new_from_settings_and_env(&hash_map, None) + ScopeMap::new_from_settings_and_env(&hash_map, None, &[]) } #[test] @@ -550,7 +570,7 @@ mod tests { .iter() .map(|(k, v)| (k.to_string(), v.to_string())) .collect(); - ScopeMap::new_from_settings_and_env(&hash_map, Some(env)) + ScopeMap::new_from_settings_and_env(&hash_map, Some(env), &[]) } #[test] @@ -609,4 +629,153 @@ mod tests { EnabledStatus::Disabled, ); } + + fn scope_map_from_all( + kv: &[(&str, &str)], + env: &env_config::EnvFilter, + default_filters: &[(&str, log::LevelFilter)], + ) -> ScopeMap { + let hash_map: HashMap = kv + .iter() + .map(|(k, v)| (k.to_string(), v.to_string())) + .collect(); + ScopeMap::new_from_settings_and_env(&hash_map, Some(env), default_filters) + } + + #[test] + fn precedence() { + // Test precedence: kv > env > default + + // Default filters - these should be overridden by env and kv when they overlap + let default_filters = &[ + ("a.b.c", log::LevelFilter::Debug), // Should be overridden by env + ("p.q.r", log::LevelFilter::Info), // Should be overridden by kv + ("x.y.z", log::LevelFilter::Warn), // Not overridden + ("crate::module::default", log::LevelFilter::Error), // Module in default + ]; + + // Environment filters - these should override default but be overridden by kv + let env_filter = + env_config::parse("a.b.c=trace,p.q=debug,m.n.o=error,crate::module::env=debug") + .unwrap(); + + // Key-value filters (highest precedence) - these should override everything + let kv_filters = &[ + ("p.q.r", "trace"), // Overrides default + ("m.n.o", "warn"), // Overrides env + ("j.k.l", "info"), // New filter + ("crate::module::env", "trace"), // Overrides env for module + ("crate::module::kv", "trace"), // New module filter + ]; + + let map = scope_map_from_all(kv_filters, &env_filter, default_filters); + + // Test scope precedence + use log::Level; + + // KV overrides all for scopes + assert_eq!( + map.is_enabled(&scope_from_scope_str("p.q.r"), None, Level::Trace), + EnabledStatus::Enabled, + "KV should override default filters for scopes" + ); + assert_eq!( + map.is_enabled(&scope_from_scope_str("m.n.o"), None, Level::Warn), + EnabledStatus::Enabled, + "KV should override env filters for scopes" + ); + assert_eq!( + map.is_enabled(&scope_from_scope_str("m.n.o"), None, Level::Debug), + EnabledStatus::Disabled, + "KV correctly limits log level" + ); + + // ENV overrides default but not KV for scopes + assert_eq!( + map.is_enabled(&scope_from_scope_str("a.b.c"), None, Level::Trace), + EnabledStatus::Enabled, + "ENV should override default filters for scopes" + ); + + // Default is used when no override exists for scopes + assert_eq!( + map.is_enabled(&scope_from_scope_str("x.y.z"), None, Level::Warn), + EnabledStatus::Enabled, + "Default filters should work when not overridden" + ); + assert_eq!( + map.is_enabled(&scope_from_scope_str("x.y.z"), None, Level::Info), + EnabledStatus::Disabled, + "Default filters correctly limit log level" + ); + + // KV overrides all for modules + assert_eq!( + map.is_enabled(&scope_new(&[""]), Some("crate::module::env"), Level::Trace), + EnabledStatus::Enabled, + "KV should override env filters for modules" + ); + assert_eq!( + map.is_enabled(&scope_new(&[""]), Some("crate::module::kv"), Level::Trace), + EnabledStatus::Enabled, + "KV module filters should work" + ); + + // ENV overrides default for modules + assert_eq!( + map.is_enabled(&scope_new(&[""]), Some("crate::module::env"), Level::Debug), + EnabledStatus::Enabled, + "ENV should override default for modules" + ); + + // Default is used when no override exists for modules + assert_eq!( + map.is_enabled( + &scope_new(&[""]), + Some("crate::module::default"), + Level::Error + ), + EnabledStatus::Enabled, + "Default filters should work for modules" + ); + assert_eq!( + map.is_enabled( + &scope_new(&[""]), + Some("crate::module::default"), + Level::Warn + ), + EnabledStatus::Disabled, + "Default filters correctly limit log level for modules" + ); + + // Test non-conflicting but similar paths + + // Test that "a.b" and "a.b.c" don't conflict (different depth) + assert_eq!( + map.is_enabled(&scope_from_scope_str("a.b.c.d"), None, Level::Trace), + EnabledStatus::Enabled, + "Scope a.b.c should inherit from a.b env filter" + ); + assert_eq!( + map.is_enabled(&scope_from_scope_str("a.b.c"), None, Level::Trace), + EnabledStatus::Enabled, + "Scope a.b.c.d should use env filter level (trace)" + ); + + // Test that similar module paths don't conflict + assert_eq!( + map.is_enabled(&scope_new(&[""]), Some("crate::module"), Level::Error), + EnabledStatus::NotConfigured, + "Module crate::module should not be affected by crate::module::default filter" + ); + assert_eq!( + map.is_enabled( + &scope_new(&[""]), + Some("crate::module::default::sub"), + Level::Error + ), + EnabledStatus::NotConfigured, + "Module crate::module::default::sub should not be affected by crate::module::default filter" + ); + } }