logiguard fork: GPUI xdg-activation keyboard-focus serial fix

Single-commit orphan branch: full zed-industries/zed @ 8c74db0 source tree
with a 3-file patch applied (no upstream history).

Patch (crates/gpui_linux/src/linux/wayland/):
  - serial.rs: add SerialKind::KeyboardEnter
  - client.rs: store wl_keyboard.enter serial; add latest_serial_of()
  - window.rs: activate() uses keyboard-enter serial (Mutter focus gate)

Mutter honors window activation only when the token carries the keyboard-
focus serial from wl_keyboard.enter; GPUI used a stale mouse-press serial.
See docs/tray-window-focus-wayland.md in logiguard.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

crates/zlog/Cargo.toml

@@ -0,0 +1,24 @@
+[package]
+name = "zlog"
+version = "0.1.0"
+edition.workspace = true
+publish.workspace = true
+license = "GPL-3.0-or-later"
+
+[lints]
+workspace = true
+
+[lib]
+path = "src/zlog.rs"
+
+[features]
+default = []
+
+[dependencies]
+collections.workspace = true
+chrono.workspace = true
+log.workspace = true
+anyhow.workspace = true
+
+[dev-dependencies]
+tempfile.workspace = true

crates/zlog/LICENSE-GPL

@@ -0,0 +1 @@
+../../LICENSE-GPL

crates/zlog/README.md

@@ -0,0 +1,15 @@
+# Zlog
+
+Use the `ZED_LOG` environment variable to control logging output for Zed
+applications and libraries. The variable accepts a comma-separated list of
+directives that specify logging levels for different modules (crates). The
+general format is for instance:
+
+```
+ZED_LOG=info,project=debug,agent=off
+```
+
+- Levels can be one of: `off`/`none`, `error`, `warn`, `info`, `debug`, or
+  `trace`.
+- You don't need to specify the global level, default is `trace` in the crate
+  and `info` set by `RUST_LOG` in Zed.

crates/zlog/src/env_config.rs

@@ -0,0 +1,122 @@
+use anyhow::Result;
+
+pub struct EnvFilter {
+    pub level_global: Option<log::LevelFilter>,
+    pub directive_names: Vec<String>,
+    pub directive_levels: Vec<log::LevelFilter>,
+}
+
+pub fn parse(filter: &str) -> Result<EnvFilter> {
+    let mut max_level = None;
+    let mut directive_names = Vec::new();
+    let mut directive_levels = Vec::new();
+
+    for directive in filter.split(',') {
+        match directive.split_once('=') {
+            Some((name, level)) => {
+                anyhow::ensure!(!level.contains('='), "Invalid directive: {directive}");
+                let level = parse_level(level.trim())?;
+                directive_names.push(name.trim().trim_end_matches(".rs").to_string());
+                directive_levels.push(level);
+            }
+            None => {
+                let Ok(level) = parse_level(directive.trim()) else {
+                    directive_names.push(directive.trim().trim_end_matches(".rs").to_string());
+                    directive_levels.push(log::LevelFilter::max() /* Enable all levels */);
+                    continue;
+                };
+                anyhow::ensure!(max_level.is_none(), "Cannot set multiple max levels");
+                max_level.replace(level);
+            }
+        };
+    }
+
+    Ok(EnvFilter {
+        level_global: max_level,
+        directive_names,
+        directive_levels,
+    })
+}
+
+fn parse_level(level: &str) -> Result<log::LevelFilter> {
+    if level.eq_ignore_ascii_case("TRACE") {
+        return Ok(log::LevelFilter::Trace);
+    }
+    if level.eq_ignore_ascii_case("DEBUG") {
+        return Ok(log::LevelFilter::Debug);
+    }
+    if level.eq_ignore_ascii_case("INFO") {
+        return Ok(log::LevelFilter::Info);
+    }
+    if level.eq_ignore_ascii_case("WARN") {
+        return Ok(log::LevelFilter::Warn);
+    }
+    if level.eq_ignore_ascii_case("ERROR") {
+        return Ok(log::LevelFilter::Error);
+    }
+    if level.eq_ignore_ascii_case("OFF") || level.eq_ignore_ascii_case("NONE") {
+        return Ok(log::LevelFilter::Off);
+    }
+    anyhow::bail!("Invalid level: {level}")
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn global_level() {
+        let input = "info";
+        let filter = parse(input).unwrap();
+
+        assert_eq!(filter.level_global.unwrap(), log::LevelFilter::Info);
+        assert!(filter.directive_names.is_empty());
+        assert!(filter.directive_levels.is_empty());
+    }
+
+    #[test]
+    fn directive_level() {
+        let input = "my_module=debug";
+        let filter = parse(input).unwrap();
+
+        assert_eq!(filter.level_global, None);
+        assert_eq!(filter.directive_names, vec!["my_module".to_string()]);
+        assert_eq!(filter.directive_levels, vec![log::LevelFilter::Debug]);
+    }
+
+    #[test]
+    fn global_level_and_directive_level() {
+        let input = "info,my_module=debug";
+        let filter = parse(input).unwrap();
+
+        assert_eq!(filter.level_global.unwrap(), log::LevelFilter::Info);
+        assert_eq!(filter.directive_names, vec!["my_module".to_string()]);
+        assert_eq!(filter.directive_levels, vec![log::LevelFilter::Debug]);
+    }
+
+    #[test]
+    fn global_level_and_bare_module() {
+        let input = "info,my_module";
+        let filter = parse(input).unwrap();
+
+        assert_eq!(filter.level_global.unwrap(), log::LevelFilter::Info);
+        assert_eq!(filter.directive_names, vec!["my_module".to_string()]);
+        assert_eq!(filter.directive_levels, vec![log::LevelFilter::max()]);
+    }
+
+    #[test]
+    fn err_when_multiple_max_levels() {
+        let input = "info,warn";
+        let result = parse(input);
+
+        assert!(result.is_err());
+    }
+
+    #[test]
+    fn err_when_invalid_level() {
+        let input = "my_module=foobar";
+        let result = parse(input);
+
+        assert!(result.is_err());
+    }
+}

crates/zlog/src/filter.rs

@@ -0,0 +1,841 @@
+use collections::HashMap;
+use std::collections::VecDeque;
+use std::sync::{
+    OnceLock, RwLock,
+    atomic::{AtomicU8, Ordering},
+};
+
+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<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.
+/// All messages more verbose than this level will be discarded
+/// by default unless specially configured.
+///
+/// This is used instead of the `log::max_level` as we need to tell the `log`
+/// crate that the max level is everything, so that we can dynamically enable
+/// logs that are more verbose than this level without the `log` crate throwing
+/// them away before we see them
+static LEVEL_ENABLED_MAX_STATIC: AtomicU8 = AtomicU8::new(LEVEL_ENABLED_MAX_DEFAULT as u8);
+
+/// A cache of the true maximum log level that _could_ be printed. This is based
+/// on the maximally verbose level that is configured by the user, and is used
+/// to filter out logs more verbose than any configured level.
+///
+/// E.g. if `LEVEL_ENABLED_MAX_STATIC `is 'info' but a user has configured some
+/// scope to print at a `debug` level, then this will be `debug`, and all
+/// `trace` logs will be discarded.
+/// Therefore, it should always be `>= LEVEL_ENABLED_MAX_STATIC`
+// 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::Warn),
+    #[cfg(any(target_os = "linux", target_os = "freebsd", target_os = "windows"))]
+    ("naga::back::spv::writer", log::LevelFilter::Warn),
+    // usvg prints a lot of warnings on rendering an SVG with partial errors, which
+    // can happen a lot with the SVG preview
+    ("usvg::parser", log::LevelFilter::Error),
+];
+
+pub fn init_env_filter(filter: env_config::EnvFilter) {
+    if let Some(level_max) = filter.level_global {
+        LEVEL_ENABLED_MAX_STATIC.store(level_max as u8, Ordering::Release)
+    }
+    if ENV_FILTER.set(filter).is_err() {
+        panic!("Environment filter cannot be initialized twice");
+    }
+}
+
+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: &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]
+        // if the message is above the maximum enabled log level
+        // (where error < warn < info etc) then disable without checking
+        // scope map
+        return false;
+    }
+    let is_enabled_by_default = level as u8 <= LEVEL_ENABLED_MAX_STATIC.load(Ordering::Acquire);
+    let global_scope_map = SCOPE_MAP.read().unwrap_or_else(|err| {
+        SCOPE_MAP.clear_poison();
+        err.into_inner()
+    });
+
+    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 = global_scope_map.is_enabled(scope, module_path, level);
+    match enabled_status {
+        EnabledStatus::NotConfigured => is_enabled_by_default,
+        EnabledStatus::Enabled => true,
+        EnabledStatus::Disabled => false,
+    }
+}
+
+pub fn refresh_from_settings(settings: &HashMap<String, String>) {
+    let env_config = ENV_FILTER.get();
+    let map_new = ScopeMap::new_from_settings_and_env(settings, env_config, DEFAULT_FILTERS);
+    let mut level_enabled_max = LEVEL_ENABLED_MAX_STATIC.load(Ordering::Acquire);
+    for entry in &map_new.entries {
+        if let Some(level) = entry.enabled {
+            level_enabled_max = level_enabled_max.max(level as u8);
+        }
+    }
+    LEVEL_ENABLED_MAX_CONFIG.store(level_enabled_max, Ordering::Release);
+
+    {
+        let mut global_map = SCOPE_MAP.write().unwrap_or_else(|err| {
+            SCOPE_MAP.clear_poison();
+            err.into_inner()
+        });
+        *global_map = map_new;
+    }
+    log::trace!("Log configuration updated");
+}
+
+fn level_filter_from_str(level_str: &str) -> Option<log::LevelFilter> {
+    use log::LevelFilter::*;
+    let level = match level_str.to_ascii_lowercase().as_str() {
+        "" => Trace,
+        "trace" => Trace,
+        "debug" => Debug,
+        "info" => Info,
+        "warn" => Warn,
+        "error" => Error,
+        "off" => Off,
+        "disable" | "no" | "none" | "disabled" => {
+            crate::warn!(
+                "Invalid log level \"{level_str}\", to disable logging set to \"off\". Defaulting to \"off\"."
+            );
+            Off
+        }
+        _ => {
+            crate::warn!("Invalid log level \"{level_str}\", ignoring");
+            return None;
+        }
+    };
+    Some(level)
+}
+
+fn scope_alloc_from_scope_str(scope_str: &str) -> Option<ScopeAlloc> {
+    let mut scope_buf = [""; SCOPE_DEPTH_MAX];
+    let mut index = 0;
+    let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR);
+    while index < SCOPE_DEPTH_MAX {
+        let Some(scope) = scope_iter.next() else {
+            break;
+        };
+        if scope.is_empty() {
+            continue;
+        }
+        scope_buf[index] = scope;
+        index += 1;
+    }
+    if index == 0 {
+        return None;
+    }
+    if scope_iter.next().is_some() {
+        crate::warn!(
+            "Invalid scope key, too many nested scopes: '{scope_str}'. Max depth is {SCOPE_DEPTH_MAX}",
+        );
+        return None;
+    }
+    let scope = scope_buf.map(|s| s.to_string());
+    Some(scope)
+}
+
+#[derive(Debug, PartialEq, Eq)]
+pub struct ScopeMap {
+    entries: Vec<ScopeMapEntry>,
+    modules: Vec<(String, log::LevelFilter)>,
+    root_count: usize,
+}
+
+#[derive(Debug, PartialEq, Eq)]
+pub struct ScopeMapEntry {
+    scope: String,
+    enabled: Option<log::LevelFilter>,
+    descendants: std::ops::Range<usize>,
+}
+
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub enum EnabledStatus {
+    Enabled,
+    Disabled,
+    NotConfigured,
+}
+
+impl ScopeMap {
+    pub fn new_from_settings_and_env(
+        items_input_map: &HashMap<String, String>,
+        env_config: Option<&env_config::EnvFilter>,
+        default_filters: &[(&str, log::LevelFilter)],
+    ) -> Self {
+        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);
+
+        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))
+        });
+
+        let new_filters = items_input_map.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.sort_by(|a, b| a.0.cmp(&b.0));
+        modules.sort_by(|(a_name, _), (b_name, _)| a_name.cmp(b_name));
+
+        let mut this = Self {
+            entries: Vec::with_capacity(items.len() * SCOPE_DEPTH_MAX),
+            modules,
+            root_count: 0,
+        };
+
+        let items_count = items.len();
+
+        struct ProcessQueueEntry {
+            parent_index: usize,
+            depth: usize,
+            items_range: std::ops::Range<usize>,
+        }
+        let mut process_queue = VecDeque::new();
+        process_queue.push_back(ProcessQueueEntry {
+            parent_index: usize::MAX,
+            depth: 0,
+            items_range: 0..items_count,
+        });
+
+        let empty_range = 0..0;
+
+        while let Some(process_entry) = process_queue.pop_front() {
+            let ProcessQueueEntry {
+                items_range,
+                depth,
+                parent_index,
+            } = process_entry;
+            let mut cursor = items_range.start;
+            let res_entries_start = this.entries.len();
+            while cursor < items_range.end {
+                let sub_items_start = cursor;
+                cursor += 1;
+                let scope_name = &items[sub_items_start].0[depth];
+                while cursor < items_range.end && &items[cursor].0[depth] == scope_name {
+                    cursor += 1;
+                }
+                let sub_items_end = cursor;
+                if scope_name.is_empty() {
+                    assert_eq!(sub_items_start + 1, sub_items_end);
+                    assert_ne!(depth, 0);
+                    assert_ne!(parent_index, usize::MAX);
+                    assert!(this.entries[parent_index].enabled.is_none());
+                    this.entries[parent_index].enabled = Some(items[sub_items_start].1);
+                    continue;
+                }
+                let is_valid_scope = !scope_name.is_empty();
+                let is_last = depth + 1 == SCOPE_DEPTH_MAX || !is_valid_scope;
+                let mut enabled = None;
+                if is_last {
+                    assert_eq!(
+                        sub_items_start + 1,
+                        sub_items_end,
+                        "Expected one item: got: {:?}",
+                        &items[items_range]
+                    );
+                    enabled = Some(items[sub_items_start].1);
+                } else {
+                    let entry_index = this.entries.len();
+                    process_queue.push_back(ProcessQueueEntry {
+                        items_range: sub_items_start..sub_items_end,
+                        parent_index: entry_index,
+                        depth: depth + 1,
+                    });
+                }
+                this.entries.push(ScopeMapEntry {
+                    scope: scope_name.to_owned(),
+                    enabled,
+                    descendants: empty_range.clone(),
+                });
+            }
+            let res_entries_end = this.entries.len();
+            if parent_index != usize::MAX {
+                this.entries[parent_index].descendants = res_entries_start..res_entries_end;
+            } else {
+                this.root_count = res_entries_end;
+            }
+        }
+
+        this
+    }
+
+    pub fn is_empty(&self) -> bool {
+        self.entries.is_empty() && self.modules.is_empty()
+    }
+
+    pub fn is_enabled<S>(
+        &self,
+        scope: &[S; SCOPE_DEPTH_MAX],
+        module_path: Option<&str>,
+        level: log::Level,
+    ) -> EnabledStatus
+    where
+        S: AsRef<str>,
+    {
+        fn search<S>(map: &ScopeMap, scope: &[S; SCOPE_DEPTH_MAX]) -> Option<log::LevelFilter>
+        where
+            S: AsRef<str>,
+        {
+            let mut enabled = None;
+            let mut cur_range = &map.entries[0..map.root_count];
+            let mut depth = 0;
+            'search: while !cur_range.is_empty()
+                && depth < SCOPE_DEPTH_MAX
+                && scope[depth].as_ref() != ""
+            {
+                for entry in cur_range {
+                    if entry.scope == scope[depth].as_ref() {
+                        enabled = entry.enabled.or(enabled);
+                        cur_range = &map.entries[entry.descendants.clone()];
+                        depth += 1;
+                        continue 'search;
+                    }
+                }
+                break 'search;
+            }
+            enabled
+        }
+
+        let mut enabled = search(self, scope);
+
+        if let Some(module_path) = module_path {
+            let scope_is_empty = scope[0].as_ref().is_empty();
+
+            if enabled.is_none() && scope_is_empty {
+                let crate_name = private::extract_crate_name_from_module_path(module_path);
+                let mut crate_name_scope = [""; SCOPE_DEPTH_MAX];
+                crate_name_scope[0] = crate_name;
+                enabled = search(self, &crate_name_scope);
+            }
+
+            if !self.modules.is_empty() {
+                let crate_name = private::extract_crate_name_from_module_path(module_path);
+                let is_scope_just_crate_name =
+                    scope[0].as_ref() == crate_name && scope[1].as_ref() == "";
+                if enabled.is_none() || is_scope_just_crate_name {
+                    for (module, filter) in &self.modules {
+                        if module == module_path {
+                            enabled.replace(*filter);
+                            break;
+                        }
+                    }
+                }
+            }
+        }
+
+        if let Some(enabled_filter) = enabled {
+            if level <= enabled_filter {
+                return EnabledStatus::Enabled;
+            }
+            return EnabledStatus::Disabled;
+        }
+        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::*;
+
+    fn scope_map_from_keys(kv: &[(&str, &str)]) -> 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, None, &[])
+    }
+
+    #[test]
+    fn test_initialization() {
+        let map = scope_map_from_keys(&[("a.b.c.d", "trace")]);
+        assert_eq!(map.root_count, 1);
+        assert_eq!(map.entries.len(), 4);
+
+        let map = scope_map_from_keys(&[]);
+        assert_eq!(map.root_count, 0);
+        assert_eq!(map.entries.len(), 0);
+
+        let map = scope_map_from_keys(&[("", "trace")]);
+        assert_eq!(map.root_count, 0);
+        assert_eq!(map.entries.len(), 0);
+
+        let map = scope_map_from_keys(&[("foo..bar", "trace")]);
+        assert_eq!(map.root_count, 1);
+        assert_eq!(map.entries.len(), 2);
+
+        let map = scope_map_from_keys(&[
+            ("a.b.c.d", "trace"),
+            ("e.f.g.h", "debug"),
+            ("i.j.k.l", "info"),
+            ("m.n.o.p", "warn"),
+            ("q.r.s.t", "error"),
+        ]);
+        assert_eq!(map.root_count, 5);
+        assert_eq!(map.entries.len(), 20);
+        assert_eq!(map.entries[0].scope, "a");
+        assert_eq!(map.entries[1].scope, "e");
+        assert_eq!(map.entries[2].scope, "i");
+        assert_eq!(map.entries[3].scope, "m");
+        assert_eq!(map.entries[4].scope, "q");
+    }
+
+    fn scope_from_scope_str(scope_str: &'static str) -> Scope {
+        let mut scope_buf = [""; SCOPE_DEPTH_MAX];
+        let mut index = 0;
+        let mut scope_iter = scope_str.split(SCOPE_STRING_SEP_STR);
+        while index < SCOPE_DEPTH_MAX {
+            let Some(scope) = scope_iter.next() else {
+                break;
+            };
+            if scope.is_empty() {
+                continue;
+            }
+            scope_buf[index] = scope;
+            index += 1;
+        }
+        assert_ne!(index, 0);
+        assert!(scope_iter.next().is_none());
+        scope_buf
+    }
+
+    #[test]
+    fn test_is_enabled() {
+        let map = scope_map_from_keys(&[
+            ("a.b.c.d", "trace"),
+            ("e.f.g.h", "debug"),
+            ("i.j.k.l", "info"),
+            ("m.n.o.p", "warn"),
+            ("q.r.s.t", "error"),
+        ]);
+        use log::Level;
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("a.b.c.d"), None, Level::Trace),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("a.b.c.d"), None, Level::Debug),
+            EnabledStatus::Enabled
+        );
+
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Debug),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Info),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("e.f.g.h"), None, Level::Trace),
+            EnabledStatus::Disabled
+        );
+
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Info),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Warn),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("i.j.k.l"), None, Level::Debug),
+            EnabledStatus::Disabled
+        );
+
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Warn),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Error),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("m.n.o.p"), None, Level::Info),
+            EnabledStatus::Disabled
+        );
+
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("q.r.s.t"), None, Level::Error),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("q.r.s.t"), None, Level::Warn),
+            EnabledStatus::Disabled
+        );
+    }
+
+    #[test]
+    fn test_is_enabled_module() {
+        let mut map = scope_map_from_keys(&[("a", "trace")]);
+        map.modules = [("a::b::c", "trace"), ("a::b::d", "debug")]
+            .map(|(k, v)| (k.to_string(), v.parse().unwrap()))
+            .to_vec();
+        use log::Level;
+        assert_eq!(
+            map.is_enabled(
+                &scope_from_scope_str("__unused__"),
+                Some("a::b::c"),
+                Level::Trace
+            ),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(
+                &scope_from_scope_str("__unused__"),
+                Some("a::b::d"),
+                Level::Debug
+            ),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(
+                &scope_from_scope_str("__unused__"),
+                Some("a::b::d"),
+                Level::Trace,
+            ),
+            EnabledStatus::Disabled
+        );
+        assert_eq!(
+            map.is_enabled(
+                &scope_from_scope_str("__unused__"),
+                Some("a::e"),
+                Level::Info
+            ),
+            EnabledStatus::NotConfigured
+        );
+        // when scope is just crate name, more specific module path overrides it
+        assert_eq!(
+            map.is_enabled(&scope_from_scope_str("a"), Some("a::b::d"), Level::Trace),
+            EnabledStatus::Disabled,
+        );
+        // but when it is scoped, the scope overrides the module path
+        assert_eq!(
+            map.is_enabled(
+                &scope_from_scope_str("a.scope"),
+                Some("a::b::d"),
+                Level::Trace
+            ),
+            EnabledStatus::Enabled,
+        );
+    }
+
+    fn scope_map_from_keys_and_env(kv: &[(&str, &str)], env: &env_config::EnvFilter) -> 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), &[])
+    }
+
+    #[test]
+    fn test_initialization_with_env() {
+        let env_filter = env_config::parse("a.b=debug,u=error").unwrap();
+        let map = scope_map_from_keys_and_env(&[], &env_filter);
+        assert_eq!(map.root_count, 2);
+        assert_eq!(map.entries.len(), 3);
+        assert_eq!(
+            map.is_enabled(&scope_new(&["a"]), None, log::Level::Debug),
+            EnabledStatus::NotConfigured
+        );
+        assert_eq!(
+            map.is_enabled(&scope_new(&["a", "b"]), None, log::Level::Debug),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_new(&["a", "b", "c"]), None, log::Level::Trace),
+            EnabledStatus::Disabled
+        );
+
+        let env_filter = env_config::parse("a.b=debug,e.f.g.h=trace,u=error").unwrap();
+        let map = scope_map_from_keys_and_env(
+            &[
+                ("a.b.c.d", "trace"),
+                ("e.f.g.h", "debug"),
+                ("i.j.k.l", "info"),
+                ("m.n.o.p", "warn"),
+                ("q.r.s.t", "error"),
+            ],
+            &env_filter,
+        );
+        assert_eq!(map.root_count, 6);
+        assert_eq!(map.entries.len(), 21);
+        assert_eq!(map.entries[0].scope, "a");
+        assert_eq!(map.entries[1].scope, "e");
+        assert_eq!(map.entries[2].scope, "i");
+        assert_eq!(map.entries[3].scope, "m");
+        assert_eq!(map.entries[4].scope, "q");
+        assert_eq!(map.entries[5].scope, "u");
+        assert_eq!(
+            map.is_enabled(&scope_new(&["a", "b", "c", "d"]), None, log::Level::Trace),
+            EnabledStatus::Enabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_new(&["a", "b", "c"]), None, log::Level::Trace),
+            EnabledStatus::Disabled
+        );
+        assert_eq!(
+            map.is_enabled(&scope_new(&["u", "v"]), None, log::Level::Warn),
+            EnabledStatus::Disabled
+        );
+        // settings override env
+        assert_eq!(
+            map.is_enabled(&scope_new(&["e", "f", "g", "h"]), None, log::Level::Trace),
+            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
+            ("crate::module::user", log::LevelFilter::Off), // Module disabled 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"
+        );
+
+        assert_eq!(
+            map.is_enabled(&scope_new(&[""]), Some("crate::module::user"), Level::Error),
+            EnabledStatus::Disabled,
+            "Module turned off in default filters is not enabled"
+        );
+
+        assert_eq!(
+            map.is_enabled(
+                &scope_new(&["crate"]),
+                Some("crate::module::user"),
+                Level::Error
+            ),
+            EnabledStatus::Disabled,
+            "Module turned off in default filters is not enabled, even with crate name as scope"
+        );
+
+        // 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"
+        );
+    }
+
+    #[test]
+    fn default_filter_crate() {
+        let default_filters = &[("crate", LevelFilter::Off)];
+        let map = scope_map_from_all(&[], &env_config::parse("").unwrap(), default_filters);
+
+        use log::Level;
+        assert_eq!(
+            map.is_enabled(&scope_new(&[""]), Some("crate::submodule"), Level::Error),
+            EnabledStatus::Disabled,
+            "crate::submodule should be disabled by disabling `crate` filter"
+        );
+    }
+}

crates/zlog/src/sink.rs

@@ -0,0 +1,336 @@
+use std::{
+    fs,
+    io::{self, Write},
+    path::PathBuf,
+    sync::{
+        Mutex, OnceLock,
+        atomic::{AtomicBool, AtomicU64, Ordering},
+    },
+};
+
+use crate::{SCOPE_STRING_SEP_CHAR, ScopeRef};
+
+// ANSI color escape codes for log levels
+const ANSI_RESET: &str = "\x1b[0m";
+const ANSI_BOLD: &str = "\x1b[1m";
+const ANSI_RED: &str = "\x1b[31m";
+const ANSI_YELLOW: &str = "\x1b[33m";
+const ANSI_GREEN: &str = "\x1b[32m";
+const ANSI_BLUE: &str = "\x1b[34m";
+const ANSI_MAGENTA: &str = "\x1b[35m";
+
+/// Is Some(file) if file output is enabled.
+static ENABLED_SINKS_FILE: Mutex<Option<std::fs::File>> = Mutex::new(None);
+static SINK_FILE_PATH: OnceLock<&'static PathBuf> = OnceLock::new();
+static SINK_FILE_PATH_ROTATE: OnceLock<&'static PathBuf> = OnceLock::new();
+
+// NB: Since this can be accessed in tests, we probably should stick to atomics here.
+/// Whether stdout output is enabled.
+static ENABLED_SINKS_STDOUT: AtomicBool = AtomicBool::new(false);
+/// Whether stderr output is enabled.
+static ENABLED_SINKS_STDERR: AtomicBool = AtomicBool::new(false);
+/// Atomic counter for the size of the log file in bytes.
+static SINK_FILE_SIZE_BYTES: AtomicU64 = AtomicU64::new(0);
+/// Maximum size of the log file before it will be rotated, in bytes.
+const SINK_FILE_SIZE_BYTES_MAX: u64 = 1024 * 1024; // 1 MB
+
+pub struct Record<'a> {
+    pub scope: ScopeRef<'a>,
+    pub level: log::Level,
+    pub message: &'a std::fmt::Arguments<'a>,
+    pub module_path: Option<&'a str>,
+    pub line: Option<u32>,
+}
+
+pub fn init_output_stdout() {
+    // Use atomics here instead of just a `static mut`, since in the context
+    // of tests these accesses can be multi-threaded.
+    ENABLED_SINKS_STDOUT.store(true, Ordering::Release);
+}
+
+pub fn init_output_stderr() {
+    ENABLED_SINKS_STDERR.store(true, Ordering::Release);
+}
+
+pub fn init_output_file(
+    path: &'static PathBuf,
+    path_rotate: Option<&'static PathBuf>,
+) -> io::Result<()> {
+    let mut enabled_sinks_file = ENABLED_SINKS_FILE
+        .try_lock()
+        .expect("Log file lock is available during init");
+
+    SINK_FILE_PATH
+        .set(path)
+        .expect("Init file output should only be called once");
+    if let Some(path_rotate) = path_rotate {
+        SINK_FILE_PATH_ROTATE
+            .set(path_rotate)
+            .expect("Init file output should only be called once");
+    }
+
+    let file = open_or_create_log_file(path, path_rotate, SINK_FILE_SIZE_BYTES_MAX)?;
+    SINK_FILE_SIZE_BYTES.store(file.metadata().map_or(0, |m| m.len()), Ordering::Release);
+    *enabled_sinks_file = Some(file);
+
+    Ok(())
+}
+
+fn open_or_create_log_file(
+    path: &PathBuf,
+    path_rotate: Option<&PathBuf>,
+    sink_file_size_bytes_max: u64,
+) -> Result<fs::File, io::Error> {
+    let size_bytes = std::fs::metadata(path).map(|metadata| metadata.len());
+    match size_bytes {
+        Ok(size_bytes) if size_bytes >= sink_file_size_bytes_max => {
+            rotate_log_file(Some(path), path_rotate).map(|it| it.unwrap())
+        }
+        _ => std::fs::OpenOptions::new()
+            .create(true)
+            .append(true)
+            .open(path),
+    }
+}
+
+const LEVEL_OUTPUT_STRINGS: [&str; 6] = [
+    "     ", // nop: ERROR = 1
+    "ERROR", //
+    "WARN ", //
+    "INFO ", //
+    "DEBUG", //
+    "TRACE", //
+];
+
+// Colors for different log levels
+static LEVEL_ANSI_COLORS: [&str; 6] = [
+    "",           // nop
+    ANSI_RED,     // Error: Red
+    ANSI_YELLOW,  // Warn: Yellow
+    ANSI_GREEN,   // Info: Green
+    ANSI_BLUE,    // Debug: Blue
+    ANSI_MAGENTA, // Trace: Magenta
+];
+
+// PERF: batching
+pub fn submit(mut record: Record) {
+    if record.module_path.is_none_or(|p| !p.ends_with(".rs")) {
+        // Only render line numbers for actual rust files emitted by `log_err` and friends
+        record.line.take();
+    }
+    if ENABLED_SINKS_STDOUT.load(Ordering::Acquire) {
+        let mut stdout = std::io::stdout().lock();
+        _ = writeln!(
+            &mut stdout,
+            "{} {ANSI_BOLD}{}{}{ANSI_RESET} {} {}",
+            chrono::Local::now().format("%Y-%m-%dT%H:%M:%S%:z"),
+            LEVEL_ANSI_COLORS[record.level as usize],
+            LEVEL_OUTPUT_STRINGS[record.level as usize],
+            SourceFmt {
+                scope: record.scope,
+                module_path: record.module_path,
+                line: record.line,
+                ansi: true,
+            },
+            record.message
+        );
+    } else if ENABLED_SINKS_STDERR.load(Ordering::Acquire) {
+        let mut stdout = std::io::stderr().lock();
+        _ = writeln!(
+            &mut stdout,
+            "{} {ANSI_BOLD}{}{}{ANSI_RESET} {} {}",
+            chrono::Local::now().format("%Y-%m-%dT%H:%M:%S%:z"),
+            LEVEL_ANSI_COLORS[record.level as usize],
+            LEVEL_OUTPUT_STRINGS[record.level as usize],
+            SourceFmt {
+                scope: record.scope,
+                module_path: record.module_path,
+                line: record.line,
+                ansi: true,
+            },
+            record.message
+        );
+    }
+    let mut file_guard = ENABLED_SINKS_FILE.lock().unwrap_or_else(|handle| {
+        ENABLED_SINKS_FILE.clear_poison();
+        handle.into_inner()
+    });
+    if let Some(file) = file_guard.as_mut() {
+        struct SizedWriter<'a> {
+            file: &'a mut std::fs::File,
+            written: u64,
+        }
+        impl io::Write for SizedWriter<'_> {
+            fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+                self.file.write(buf)?;
+                self.written += buf.len() as u64;
+                Ok(buf.len())
+            }
+
+            fn flush(&mut self) -> io::Result<()> {
+                self.file.flush()
+            }
+        }
+        let file_size_bytes = {
+            let mut writer = SizedWriter { file, written: 0 };
+            _ = writeln!(
+                &mut writer,
+                "{} {} {} {}",
+                chrono::Local::now().format("%Y-%m-%dT%H:%M:%S%:z"),
+                LEVEL_OUTPUT_STRINGS[record.level as usize],
+                SourceFmt {
+                    scope: record.scope,
+                    module_path: record.module_path,
+                    line: record.line,
+                    ansi: false,
+                },
+                record.message
+            );
+            SINK_FILE_SIZE_BYTES.fetch_add(writer.written, Ordering::AcqRel) + writer.written
+        };
+        if file_size_bytes > SINK_FILE_SIZE_BYTES_MAX {
+            *file_guard = None;
+            let file = rotate_log_file(SINK_FILE_PATH.get(), SINK_FILE_PATH_ROTATE.get());
+            match file {
+                Ok(Some(file)) => *file_guard = Some(file),
+                Ok(None) => {}
+                Err(e) => {
+                    eprintln!("Failed to open log file: {e}")
+                }
+            }
+            SINK_FILE_SIZE_BYTES.store(0, Ordering::Release);
+        }
+    }
+}
+
+pub fn flush() {
+    if ENABLED_SINKS_STDOUT.load(Ordering::Acquire) {
+        _ = std::io::stdout().lock().flush();
+    }
+    let mut file = ENABLED_SINKS_FILE.lock().unwrap_or_else(|handle| {
+        ENABLED_SINKS_FILE.clear_poison();
+        handle.into_inner()
+    });
+    if let Some(file) = file.as_mut()
+        && let Err(err) = file.flush()
+    {
+        eprintln!("Failed to flush log file: {}", err);
+    }
+}
+
+struct SourceFmt<'a> {
+    scope: ScopeRef<'a>,
+    module_path: Option<&'a str>,
+    line: Option<u32>,
+    ansi: bool,
+}
+
+impl std::fmt::Display for SourceFmt<'_> {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        use std::fmt::Write;
+        f.write_char('[')?;
+        if self.ansi {
+            f.write_str(ANSI_BOLD)?;
+        }
+        // NOTE: if no longer prefixing scopes with their crate name, check if scope[0] is empty
+        if (self.scope[1].is_empty() && self.module_path.is_some()) || self.scope[0].is_empty() {
+            f.write_str(self.module_path.unwrap_or("?"))?;
+        } else {
+            f.write_str(self.scope[0])?;
+            for subscope in &self.scope[1..] {
+                if subscope.is_empty() {
+                    break;
+                }
+                f.write_char(SCOPE_STRING_SEP_CHAR)?;
+                f.write_str(subscope)?;
+            }
+        }
+        if let Some(line) = self.line {
+            f.write_char(':')?;
+            line.fmt(f)?;
+        }
+        if self.ansi {
+            f.write_str(ANSI_RESET)?;
+        }
+        f.write_char(']')?;
+        Ok(())
+    }
+}
+
+fn rotate_log_file<PathRef>(
+    path: Option<PathRef>,
+    path_rotate: Option<PathRef>,
+) -> std::io::Result<Option<fs::File>>
+where
+    PathRef: AsRef<std::path::Path>,
+{
+    let path = path.as_ref().map(PathRef::as_ref);
+    let rotation_error = match (path, path_rotate) {
+        (Some(_), None) => Some(anyhow::anyhow!("No rotation log file path configured")),
+        (None, _) => Some(anyhow::anyhow!("No log file path configured")),
+        (Some(path), Some(path_rotate)) => fs::copy(path, path_rotate)
+            .err()
+            .map(|err| anyhow::anyhow!(err)),
+    };
+    if let Some(err) = rotation_error {
+        eprintln!("Log file rotation failed. Truncating log file anyways: {err}",);
+    }
+    path.map(|path| {
+        fs::OpenOptions::new()
+            .create(true)
+            .write(true)
+            .truncate(true)
+            .open(path)
+    })
+    .transpose()
+}
+
+#[cfg(test)]
+mod tests {
+
+    use super::*;
+
+    #[test]
+    fn test_open_or_create_log_file_rotate() {
+        let temp_dir = tempfile::tempdir().unwrap();
+        let log_file_path = temp_dir.path().join("log.txt");
+        let rotation_log_file_path = temp_dir.path().join("log_rotated.txt");
+
+        let contents = String::from("Hello, world!");
+        std::fs::write(&log_file_path, &contents).unwrap();
+
+        open_or_create_log_file(&log_file_path, Some(&rotation_log_file_path), 4).unwrap();
+
+        assert!(log_file_path.exists());
+        assert_eq!(log_file_path.metadata().unwrap().len(), 0);
+        assert!(rotation_log_file_path.exists());
+        assert_eq!(std::fs::read_to_string(&log_file_path).unwrap(), "");
+    }
+
+    #[test]
+    fn test_open_or_create_log_file() {
+        let temp_dir = tempfile::tempdir().unwrap();
+        let log_file_path = temp_dir.path().join("log.txt");
+        let rotation_log_file_path = temp_dir.path().join("log_rotated.txt");
+
+        let contents = String::from("Hello, world!");
+        std::fs::write(&log_file_path, &contents).unwrap();
+
+        open_or_create_log_file(&log_file_path, Some(&rotation_log_file_path), !0).unwrap();
+
+        assert!(log_file_path.exists());
+        assert_eq!(log_file_path.metadata().unwrap().len(), 13);
+        assert!(!rotation_log_file_path.exists());
+        assert_eq!(std::fs::read_to_string(&log_file_path).unwrap(), contents);
+    }
+
+    /// Regression test, ensuring that if log level values change we are made aware
+    #[test]
+    fn test_log_level_names() {
+        assert_eq!(LEVEL_OUTPUT_STRINGS[log::Level::Error as usize], "ERROR");
+        assert_eq!(LEVEL_OUTPUT_STRINGS[log::Level::Warn as usize], "WARN ");
+        assert_eq!(LEVEL_OUTPUT_STRINGS[log::Level::Info as usize], "INFO ");
+        assert_eq!(LEVEL_OUTPUT_STRINGS[log::Level::Debug as usize], "DEBUG");
+        assert_eq!(LEVEL_OUTPUT_STRINGS[log::Level::Trace as usize], "TRACE");
+    }
+}

crates/zlog/src/zlog.rs

@@ -0,0 +1,409 @@
+//! # logger
+pub use log as log_impl;
+
+mod env_config;
+pub mod filter;
+pub mod sink;
+
+pub use sink::{flush, init_output_file, init_output_stderr, init_output_stdout};
+
+pub const SCOPE_DEPTH_MAX: usize = 4;
+
+pub fn init() {
+    if let Err(err) = try_init(None) {
+        log::error!("{err}");
+        eprintln!("{err}");
+    }
+}
+
+pub fn try_init(filter: Option<String>) -> anyhow::Result<()> {
+    log::set_logger(&ZLOG)?;
+    log::set_max_level(log::LevelFilter::max());
+    process_env(filter);
+    filter::refresh_from_settings(&std::collections::HashMap::default());
+    Ok(())
+}
+
+pub fn init_test() {
+    if get_env_config().is_some() && try_init(None).is_ok() {
+        init_output_stdout();
+    }
+}
+
+fn get_env_config() -> Option<String> {
+    std::env::var("ZED_LOG")
+        .or_else(|_| std::env::var("RUST_LOG"))
+        .ok()
+        .or_else(|| {
+            if std::env::var("CI").is_ok() {
+                Some("info".to_owned())
+            } else {
+                None
+            }
+        })
+}
+
+pub fn process_env(filter: Option<String>) {
+    let Some(env_config) = get_env_config().or(filter) else {
+        return;
+    };
+    match env_config::parse(&env_config) {
+        Ok(filter) => {
+            filter::init_env_filter(filter);
+        }
+        Err(err) => {
+            eprintln!("Failed to parse log filter: {}", err);
+        }
+    }
+}
+
+static ZLOG: Zlog = Zlog {};
+
+pub struct Zlog {}
+
+impl log::Log for Zlog {
+    fn enabled(&self, metadata: &log::Metadata) -> bool {
+        filter::is_possibly_enabled_level(metadata.level())
+    }
+
+    fn log(&self, record: &log::Record) {
+        if !self.enabled(record.metadata()) {
+            return;
+        }
+        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_ref_new(&[crate_name]);
+                let module_scope = private::scope_ref_new(&[module_path]);
+                (crate_name_scope, module_scope)
+            }
+            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) {
+            return;
+        }
+        sink::submit(sink::Record {
+            scope: module_scope,
+            level,
+            message: record.args(),
+            // PERF(batching): store non-static paths in a cache + leak them and pass static str here
+            module_path,
+            line: record.line(),
+        });
+    }
+
+    fn flush(&self) {
+        sink::flush();
+    }
+}
+
+#[macro_export]
+macro_rules! log {
+    ($logger:expr, $level:expr, $($arg:tt)+) => {
+        let level = $level;
+        let logger = $logger;
+        let enabled = $crate::filter::is_scope_enabled(&logger.scope, Some(module_path!()), level);
+        if enabled {
+            $crate::sink::submit($crate::sink::Record {
+                scope: logger.scope,
+                level,
+                message: &format_args!($($arg)+),
+                module_path: Some(module_path!()),
+                line: Some(line!()),
+            });
+        }
+    }
+}
+
+#[macro_export]
+macro_rules! trace {
+    ($logger:expr => $($arg:tt)+) => {
+        $crate::log!($logger, $crate::log_impl::Level::Trace, $($arg)+);
+    };
+    ($($arg:tt)+) => {
+        $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Trace, $($arg)+);
+    };
+}
+
+#[macro_export]
+macro_rules! debug {
+    ($logger:expr => $($arg:tt)+) => {
+        $crate::log!($logger, $crate::log_impl::Level::Debug, $($arg)+);
+    };
+    ($($arg:tt)+) => {
+        $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Debug, $($arg)+);
+    };
+}
+
+#[macro_export]
+macro_rules! info {
+    ($logger:expr => $($arg:tt)+) => {
+        $crate::log!($logger, $crate::log_impl::Level::Info, $($arg)+);
+    };
+    ($($arg:tt)+) => {
+        $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Info, $($arg)+);
+    };
+}
+
+#[macro_export]
+macro_rules! warn {
+    ($logger:expr => $($arg:tt)+) => {
+        $crate::log!($logger, $crate::log_impl::Level::Warn, $($arg)+);
+    };
+    ($($arg:tt)+) => {
+        $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Warn, $($arg)+);
+    };
+}
+
+#[macro_export]
+macro_rules! error {
+    ($logger:expr => $($arg:tt)+) => {
+        $crate::log!($logger, $crate::log_impl::Level::Error, $($arg)+);
+    };
+    ($($arg:tt)+) => {
+        $crate::log!($crate::default_logger!(), $crate::log_impl::Level::Error, $($arg)+);
+    };
+}
+
+/// Creates a timer that logs the duration it was active for either when
+/// it is dropped, or when explicitly stopped using the `end` method.
+/// Logs at the `trace` level.
+/// Note that it will include time spent across await points
+/// (i.e. should not be used to measure the performance of async code)
+/// However, this is a feature not a bug, as it allows for a more accurate
+/// understanding of how long the action actually took to complete, including
+/// interruptions, which can help explain why something may have timed out,
+/// why it took longer to complete than it would have had the await points resolved
+/// immediately, etc.
+#[macro_export]
+macro_rules! time {
+    ($logger:expr => $name:expr) => {
+        $crate::Timer::new($logger, $name)
+    };
+    ($name:expr) => {
+        $crate::time!($crate::default_logger!() => $name)
+    };
+}
+
+#[macro_export]
+macro_rules! scoped {
+    ($parent:expr => $name:expr) => {{
+        $crate::scoped_logger($parent, $name)
+    }};
+    ($name:expr) => {
+        $crate::scoped!($crate::default_logger!() => $name)
+    };
+}
+
+pub const fn scoped_logger(parent: Logger, name: &'static str) -> Logger {
+    let mut scope = parent.scope;
+    let mut index = 1; // always have crate/module name
+    while index < scope.len() && !scope[index].is_empty() {
+        index += 1;
+    }
+    if index >= scope.len() {
+        #[cfg(debug_assertions)]
+        {
+            panic!("Scope overflow trying to add scope... ignoring scope");
+        }
+    }
+    scope[index] = name;
+    Logger { scope }
+}
+
+#[macro_export]
+macro_rules! default_logger {
+    () => {
+        $crate::Logger {
+            scope: $crate::private::scope_new(&[$crate::crate_name!()]),
+        }
+    };
+}
+
+#[macro_export]
+macro_rules! crate_name {
+    () => {
+        $crate::private::extract_crate_name_from_module_path(module_path!())
+    };
+}
+
+/// functions that are used in macros, and therefore must be public,
+/// but should not be used directly
+pub mod private {
+    use super::*;
+
+    pub const fn extract_crate_name_from_module_path(module_path: &str) -> &str {
+        let mut i = 0;
+        let mod_path_bytes = module_path.as_bytes();
+        let mut index = mod_path_bytes.len();
+        while i + 1 < mod_path_bytes.len() {
+            if mod_path_bytes[i] == b':' && mod_path_bytes[i + 1] == b':' {
+                index = i;
+                break;
+            }
+            i += 1;
+        }
+        let Some((crate_name, _)) = module_path.split_at_checked(index) else {
+            return module_path;
+        };
+        crate_name
+    }
+
+    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;
+        while i < scopes.len() {
+            scope[i] = scopes[i];
+            i += 1;
+        }
+        scope
+    }
+
+    pub fn scope_alloc_new(scopes: &[&str]) -> ScopeAlloc {
+        assert!(scopes.len() <= SCOPE_DEPTH_MAX);
+        let mut scope = [""; SCOPE_DEPTH_MAX];
+        scope[0..scopes.len()].copy_from_slice(scopes);
+        scope.map(|s| s.to_string())
+    }
+
+    pub fn scope_to_alloc(scope: &Scope) -> ScopeAlloc {
+        scope.map(|s| s.to_string())
+    }
+}
+
+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 = '.';
+
+#[derive(Clone, Copy, Debug, PartialEq, Eq)]
+pub struct Logger {
+    pub scope: Scope,
+}
+
+impl log::Log for Logger {
+    fn enabled(&self, metadata: &log::Metadata) -> bool {
+        filter::is_possibly_enabled_level(metadata.level())
+    }
+
+    fn log(&self, record: &log::Record) {
+        if !self.enabled(record.metadata()) {
+            return;
+        }
+        let level = record.metadata().level();
+        if !filter::is_scope_enabled(&self.scope, Some(record.target()), level) {
+            return;
+        }
+        sink::submit(sink::Record {
+            scope: self.scope,
+            level,
+            message: record.args(),
+            module_path: record.module_path(),
+            line: record.line(),
+        });
+    }
+
+    fn flush(&self) {
+        sink::flush();
+    }
+}
+
+pub struct Timer {
+    pub logger: Logger,
+    pub start_time: std::time::Instant,
+    pub name: &'static str,
+    pub warn_if_longer_than: Option<std::time::Duration>,
+    pub done: bool,
+}
+
+impl Drop for Timer {
+    fn drop(&mut self) {
+        self.finish();
+    }
+}
+
+impl Timer {
+    #[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"]
+    pub fn new(logger: Logger, name: &'static str) -> Self {
+        Self {
+            logger,
+            name,
+            start_time: std::time::Instant::now(),
+            warn_if_longer_than: None,
+            done: false,
+        }
+    }
+
+    pub fn warn_if_gt(mut self, warn_limit: std::time::Duration) -> Self {
+        self.warn_if_longer_than = Some(warn_limit);
+        self
+    }
+
+    pub fn end(mut self) {
+        self.finish();
+    }
+
+    fn finish(&mut self) {
+        if self.done {
+            return;
+        }
+        let elapsed = self.start_time.elapsed();
+        if let Some(warn_limit) = self.warn_if_longer_than
+            && elapsed > warn_limit
+        {
+            crate::warn!(
+                self.logger =>
+                "Timer '{}' took {:?}. Which was longer than the expected limit of {:?}",
+                self.name,
+                elapsed,
+                warn_limit
+            );
+            self.done = true;
+            return;
+        }
+        crate::trace!(
+            self.logger =>
+            "Timer '{}' finished in {:?}",
+            self.name,
+            elapsed
+        );
+        self.done = true;
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn test_crate_name() {
+        assert_eq!(crate_name!(), "zlog");
+        assert_eq!(
+            private::extract_crate_name_from_module_path("my_speedy_⚡️_crate::some_module"),
+            "my_speedy_⚡️_crate"
+        );
+        assert_eq!(
+            private::extract_crate_name_from_module_path("my_speedy_crate_⚡️::some_module"),
+            "my_speedy_crate_⚡️"
+        );
+        assert_eq!(
+            private::extract_crate_name_from_module_path("my_speedy_crate_:⚡️:some_module"),
+            "my_speedy_crate_:⚡️:some_module"
+        );
+        assert_eq!(
+            private::extract_crate_name_from_module_path("my_speedy_crate_::⚡️some_module"),
+            "my_speedy_crate_"
+        );
+    }
+}