zlog: Add default filters (#29244)

Added default filters to `zlog`, a piece that was present in our
`simple_log` setup, but was missed when switching to `zlog`, resulting
in logspam primarily on linux.

also - more explicit precedence & precedence testing

Release Notes:

- N/A
This commit is contained in:
Ben Kunkle 2025-04-22 18:54:56 -04:00 committed by GitHub
parent 3705986fac
commit 75ab8ff9a1
No known key found for this signature in database
GPG key ID: B5690EEEBB952194

View file

@ -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 // 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); 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) { pub fn init_env_filter(filter: env_config::EnvFilter) {
if let Some(level_max) = filter.level_global { if let Some(level_max) = filter.level_global {
unsafe { LEVEL_ENABLED_MAX_STATIC = level_max } unsafe { LEVEL_ENABLED_MAX_STATIC = level_max }
@ -92,7 +101,7 @@ pub(crate) fn refresh() {
pub fn refresh_from_settings(settings: &HashMap<String, String>) { pub fn refresh_from_settings(settings: &HashMap<String, String>) {
let env_config = ENV_FILTER.get(); 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 }; let mut level_enabled_max = unsafe { LEVEL_ENABLED_MAX_STATIC };
for entry in &map_new.entries { for entry in &map_new.entries {
if let Some(level) = entry.enabled { if let Some(level) = entry.enabled {
@ -111,7 +120,7 @@ pub fn refresh_from_settings(settings: &HashMap<String, String>) {
log::trace!("Log configuration updated"); log::trace!("Log configuration updated");
} }
fn level_filter_from_str(level_str: &String) -> Option<log::LevelFilter> { fn level_filter_from_str(level_str: &str) -> Option<log::LevelFilter> {
use log::LevelFilter::*; use log::LevelFilter::*;
let level = match level_str.to_ascii_lowercase().as_str() { let level = match level_str.to_ascii_lowercase().as_str() {
"" => Trace, "" => Trace,
@ -135,7 +144,7 @@ fn level_filter_from_str(level_str: &String) -> Option<log::LevelFilter> {
return Some(level); return Some(level);
} }
fn scope_alloc_from_scope_str(scope_str: &String) -> Option<ScopeAlloc> { fn scope_alloc_from_scope_str(scope_str: &str) -> Option<ScopeAlloc> {
let mut scope_buf = [""; SCOPE_DEPTH_MAX]; let mut scope_buf = [""; SCOPE_DEPTH_MAX];
let mut index = 0; let mut index = 0;
let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR); let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR);
@ -187,46 +196,57 @@ impl ScopeMap {
pub fn new_from_settings_and_env( pub fn new_from_settings_and_env(
items_input_map: &HashMap<String, String>, items_input_map: &HashMap<String, String>,
env_config: Option<&env_config::EnvFilter>, env_config: Option<&env_config::EnvFilter>,
default_filters: &[(&str, log::LevelFilter)],
) -> Self { ) -> Self {
let mut items = Vec::with_capacity( let mut items = Vec::<(ScopeAlloc, log::LevelFilter)>::with_capacity(
items_input_map.len() + env_config.map_or(0, |c| c.directive_names.len()), items_input_map.len()
+ env_config.map_or(0, |c| c.directive_names.len())
+ default_filters.len(),
); );
let mut modules = Vec::with_capacity(4); let mut modules = Vec::with_capacity(4);
if let Some(env_filter) = env_config { let env_filters = env_config.iter().flat_map(|env_filter| {
// TODO: parse on load instead of every reload env_filter
items.extend( .directive_names
env_filter .iter()
.directive_names .zip(env_filter.directive_levels.iter())
.iter() .map(|(scope_str, level_filter)| (scope_str.as_str(), *level_filter))
.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)?;
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)); items.sort_by(|a, b| a.0.cmp(&b.0));
modules.sort_by(|(a_name, _), (b_name, _)| a_name.cmp(b_name)); modules.sort_by(|(a_name, _), (b_name, _)| a_name.cmp(b_name));
@ -376,7 +396,7 @@ mod tests {
.iter() .iter()
.map(|(k, v)| (k.to_string(), v.to_string())) .map(|(k, v)| (k.to_string(), v.to_string()))
.collect(); .collect();
ScopeMap::new_from_settings_and_env(&hash_map, None) ScopeMap::new_from_settings_and_env(&hash_map, None, &[])
} }
#[test] #[test]
@ -550,7 +570,7 @@ mod tests {
.iter() .iter()
.map(|(k, v)| (k.to_string(), v.to_string())) .map(|(k, v)| (k.to_string(), v.to_string()))
.collect(); .collect();
ScopeMap::new_from_settings_and_env(&hash_map, Some(env)) ScopeMap::new_from_settings_and_env(&hash_map, Some(env), &[])
} }
#[test] #[test]
@ -609,4 +629,153 @@ mod tests {
EnabledStatus::Disabled, EnabledStatus::Disabled,
); );
} }
fn scope_map_from_all(
kv: &[(&str, &str)],
env: &env_config::EnvFilter,
default_filters: &[(&str, log::LevelFilter)],
) -> ScopeMap {
let hash_map: HashMap<String, String> = 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"
);
}
} }