Rust in Everything
基于 tracing-core 0.1.36

Metadata、Level 与 LevelFilter

主线位置：两条主线的共同起点。info! 和 info_span! 展开后的第一件事都是比较级别：先和编译期的 STATIC_MAX_LEVEL 比，再和这一页的 LevelFilter::current() 比；后面每一道门问 subscriber 时，递过去的也都是这一页的 Metadata。

flowchart TB
  macroexp["info! 展开"] --> meta["static META：Metadata"]
  macroexp --> cs["static __CALLSITE"]
  meta -->|"fields 里的 Identifier"| cs
  cs -->|"meta 字段"| meta
  macroexp --> gate1["Level 对 STATIC_MAX_LEVEL"]
  gate1 --> gate2["Level 对 LevelFilter::current"]
  gate2 --> maxlvl["MAX_LEVEL：AtomicUsize"]
  gate2 --> later["调用点的 Interest 缓存"]

Metadata 描述「这是哪里的一条什么样的记录」，在编译期就定了；Level 是其中最常用来过滤的一项；LevelFilter 是「到哪一级为止」，全局那一份存在一个原子变量里，宏每次经过都读它。三样都在 tracing-core 的 metadata.rs。调用点和它缓存的 Interest 在下一页 Callsite 与 Interest 缓存。

Metadata：每个调用点一份

Metadata：

pub struct Metadata<'a> {
    /// The name of the span described by this metadata.
    name: &'static str,

    /// The part of the system that the span that this metadata describes
    /// occurred in.
    target: &'a str,

    /// The level of verbosity of the described span.
    level: Level,

    /// The name of the Rust module where the span occurred, or `None` if this
    /// could not be determined.
    module_path: Option<&'a str>,

    // ...
    file: Option<&'a str>,

    // ...
    line: Option<u32>,

    /// The names of the key-value fields attached to the described span or
    /// event.
    fields: field::FieldSet,

    /// The kind of the callsite.
    kind: Kind,
}
字段宏填的值用途
namespan 写的名字；事件是 "event 文件:行"span 的名字；事件一般不看
target默认 module_path!()，可用 target: "..." 改EnvFilter 的 my_crate::db=debug 匹配的就是它
level宏名决定（info! 是 INFO）级别过滤
module_path、file、linemodule_path!()、file!()、line!()输出里的位置
fields字段名数组 + 调用点标识见 字段：Field、Value 与 Visit
kindKind::EVENT、Kind::SPAN，enabled! 用 Kind::HINT区分事件和 span

Kind 是一个 u8 位集：EVENT_BIT、SPAN_BIT、HINT_BIT 分别是第 0、1、2 位。HINT 的文档说 subscriber 看到它可以认为「永远不会收到一条带这份元数据的完整事件」，enabled! 只问不记，用的就是它。

静态的 META 和 __CALLSITE 互相指着

Metadata 只有一个 const fn new 构造器（Metadata::new），所以宏可以在 static 里构造它。tracing 的 callsite2! 是 event!、span! 共用的那一段：

        static META: $crate::Metadata<'static> = {
            $crate::metadata! {
                name: $name,
                target: $target,
                level: $lvl,
                fields: $crate::fieldset!( $($fields)* ),
                callsite: &__CALLSITE,
                kind: $kind,
            }
        };
        $crate::callsite::DefaultCallsite::new(&META)

callsite2! 自己的结果被赋给外面的 static __CALLSITE（见 event!），于是两个 static 互相引用：__CALLSITE 里存 &META，META 的 FieldSet 里存 &__CALLSITE。tracing-core 的 metadata! 把调用点包成 identify_callsite!($callsite)，也就是 Identifier（一个 &'static dyn Callsite），文件、行号、模块路径则用 file!()、line!()、module_path!() 填成 Some(...)。static 之间允许这样互相取地址，因为地址在编译期就确定，不需要先算出值。

结果是：程序里每一个 info! 在二进制里对应一份 Metadata 和一份调用点，运行时一次也不构造。宏展开的全貌在 宏展开：一个 info! 变成了什么。

Metadata 的 PartialEq（源码）利用了「一个调用点只有一份元数据」：先比指针，release 构建（cfg!(not(debug_assertions))）里只比 callsite()；debug 构建里才把八个字段逐个比一遍，用来发现行为不正常的自定义 Callsite。

看一眼真实的 Metadata

subscriber 在 register_callsite 里第一次拿到每个调用点的 Metadata。下面的程序在那里把它打印出来，顺带测这一页后面要讲的几件事：

tracing = "=0.1.44"
tracing-core = "=0.1.36"

use tracing::level_filters::LevelFilter;
use tracing::span::{Attributes, Id, Record};
use tracing::{Event, Level, Metadata, Subscriber};
use tracing_core::Dispatch;

struct Show;

impl Subscriber for Show {
  fn register_callsite(&self, meta: &'static Metadata<'static>) -> tracing::subscriber::Interest {
    println!("register_callsite: {meta:#?}");
    tracing::subscriber::Interest::always()
  }
  fn max_level_hint(&self) -> Option<LevelFilter> {
    Some(LevelFilter::INFO)
  }
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    true
  }
  fn event(&self, _: &Event<'_>) {}
  fn new_span(&self, _: &Attributes<'_>) -> Id {
    Id::from_u64(1)
  }
  fn record(&self, _: &Id, _: &Record<'_>) {}
  fn record_follows_from(&self, _: &Id, _: &Id) {}
  fn enter(&self, _: &Id) {}
  fn exit(&self, _: &Id) {}
}

fn main() {
  println!("TRACE > ERROR: {}", Level::TRACE > Level::ERROR);
  println!("OFF < ERROR: {}", LevelFilter::OFF < LevelFilter::ERROR);
  println!("ERROR <= OFF: {}", Level::ERROR <= LevelFilter::OFF);
  println!("WARN <= INFO filter: {}", Level::WARN <= LevelFilter::INFO);
  println!(
    "size_of Level={} LevelFilter={} Option<LevelFilter>={}",
    size_of::<Level>(),
    size_of::<LevelFilter>(),
    size_of::<Option<LevelFilter>>(),
  );
  for s in ["", "0", "3", "Debug", "verbose"] {
    println!("{s:?}.parse::<LevelFilter>() = {:?}", s.parse::<LevelFilter>());
  }
  for s in ["0", "3"] {
    println!("{s:?}.parse::<Level>() = {:?}", s.parse::<Level>().map_err(|e| e.to_string()));
  }

  println!("current before any Dispatch = {}", LevelFilter::current());
  let dispatch = Dispatch::new(Show);
  println!("current after Dispatch::new(Show) = {}", LevelFilter::current());
  tracing::dispatcher::with_default(&dispatch, || {
    tracing::info!(user = "ann", "login");
  });
}

M2 Max、rustc 1.99.0，跑 3 次，除了 callsite 里的两个地址，输出相同。其中 Metadata 那一段：

register_callsite: Metadata {
    name: "event src/bin/levels.rs:51",
    target: "levels",
    level: Level(
        Info,
    ),
    module_path: "levels",
    location: src/bin/levels.rs:51,
    fields: {message, user},
    callsite: Identifier(Pointer { addr: 0x102098220, metadata: DynMetadata(0x102094170) }),
    kind: Kind(EVENT),
}
  • 事件的 name 是宏拼出来的 "event 文件:行"。
  • target 和 module_path 都是 levels：二进制 crate 的模块路径就是 crate 名。
  • fields 里 message 排在 user 前面：info!(user = "ann", "login") 原样变成 event!(target: module_path!(), Level::INFO, { user = "ann", "login" })，fieldset! 的兜底分支在生成字段名时把 message 放到最前面（见宏展开）。
  • callsite 是一个胖指针，数据地址指向那个 static __CALLSITE，每次运行不同。
📝NOTE
没有蠢问题

问： 宏生成的都是 Metadata<'static>，DefaultCallsite 也只存 &'static Metadata<'static>，这个类型为什么还要带一个生命周期 'a？

答： 因为不是所有 Metadata 都来自宏。tracing-log 把 log crate 的记录转成 tracing 的元数据：AsTrace for log::Metadata<'a> 的产物是 Metadata<'a>，target 借自那条 log::Record，记录用完就没了。所以 name 固定是 &'static str，target、module_path、file 是 &'a str。两种入口也就分开了：register_callsite 只接受 &'static Metadata<'static>（要长期缓存），enabled 接受 &Metadata<'_>（只在这一刻用）。log 怎么进 tracing 见 log 互通。

Level：五个级别，内部数值是倒着的

Level 包着一个私有的 LevelInner：

#[repr(usize)]
#[derive(Copy, Clone, Debug, Hash, Eq, PartialEq)]
enum LevelInner {
    /// The "trace" level.
    ///
    /// Designates very low priority, often extremely verbose, information.
    Trace = 0,
    // ...
    Debug = 1,
    // ...
    Info = 2,
    // ...
    Warn = 3,
    // ...
    Error = 4,
}

对外的比较规则是「越详细越大」：TRACE > DEBUG > INFO > WARN > ERROR，和 log crate 一样（log 0.4 的 Level 是 Error = 1 到 Trace = 5，数值本身就是这个方向）。tracing 内部的数值却反过来，Trace = 0、Error = 4，于是 PartialOrd 不能 derive，得手写成把左右两边对调再比，比如 impl PartialOrd for Level 里的：

    #[inline(always)]
    fn lt(&self, other: &Level) -> bool {
        (other.0 as usize) < (self.0 as usize)
    }

为什么要倒过来，源码在这些比较实现前面写了一大段 /!\ BIG, IMPORTANT WARNING /!\，理由有三条：

  1. LevelFilter 必须是 Option<Level>（历史上 tracing 的 LevelFilter 就提供了 Level 和它之间的 const fn 转换，改不了），derive 出来的比较不会编译成整数比较，所以全部手写，两边都先转成 usize。
  2. 最热的那次比较发生在 tracing 的宏里，也就是在依赖 tracing-core 的另一个 crate 里。跨 crate 内联需要 #[inline]，而且真正被调用的是 lt、le、gt、ge，只给 partial_cmp 加不够，所以四个方法都写出来，都标 #[inline(always)]。
  3. 数值倒过来，是为了让 Option<Level> 的 None 落在一端。Option<枚举> 的 niche 优化把「最大判别值 + 1」用作 None，这里就是 5。None 表示 OFF，OFF 要比所有级别都「安静」；要让一次 cmp 就比完，OFF 必须和 ERROR 相邻、在 TRACE 的另一头，于是 ERROR 取 4，TRACE 取 0。

注释的结论是「Don't change it unless you know what you're doing」。上面程序的前几行验证了对外的方向和大小：

TRACE > ERROR: true
OFF < ERROR: true
ERROR <= OFF: false
WARN <= INFO filter: true
size_of Level=8 LevelFilter=8 Option<LevelFilter>=8

Level 是 #[repr(usize)]，8 字节；LevelFilter 也是 8 字节，None 没有额外占地方；再套一层 Option 还是 8 字节，又用了下一个空位。Level::ERROR <= LevelFilter::OFF 是 false：在 OFF 之下，什么级别都不放行。

LevelFilter 与全局 MAX_LEVEL

LevelFilter 就是 Option<Level>：

#[repr(transparent)]
#[derive(Copy, Clone, Eq, PartialEq, Hash)]
pub struct LevelFilter(Option<Level>);

它比 Level 多一个 LevelFilter::OFF（LevelFilter(None)）。规则是「级别 <= filter 就放行」：LevelFilter::INFO 放行 ERROR、WARN、INFO。

全局只有一个 LevelFilter，存在 MAX_LEVEL 里：

static MAX_LEVEL: AtomicUsize = AtomicUsize::new(LevelFilter::OFF_USIZE);

OFF_USIZE 是 LevelInner::Error as usize + 1，也就是 5，正好等于 niche 给 None 选的值。读它的是 LevelFilter::current：

    #[inline(always)]
    pub fn current() -> Self {
        match MAX_LEVEL.load(Ordering::Relaxed) {
            Self::ERROR_USIZE => Self::ERROR,
            Self::WARN_USIZE => Self::WARN,
            Self::INFO_USIZE => Self::INFO,
            Self::DEBUG_USIZE => Self::DEBUG,
            Self::TRACE_USIZE => Self::TRACE,
            Self::OFF_USIZE => Self::OFF,
            #[cfg(debug_assertions)]
            unknown => unreachable!(
                // ...
            ),
            #[cfg(not(debug_assertions))]
            _ => unsafe {
                // ...
                core::hint::unreachable_unchecked()
            },
        }
    }

每个分支左边的整数和右边 LevelFilter 的内存表示相同，release 构建里其余的值用 unreachable_unchecked 排除，编译器就能把整个 match 变成一次恒等转换，注释说目标是在 x86 上只剩一条 mov。安全前提也写在注释里：MAX_LEVEL 只被 set_max 写，而 set_max 只接受合法的 LevelFilter。

用 Relaxed 读，因为这只是一个提示：读到稍旧的值，最多是多放行一次、交给后面的门再判断，或者少记一条在配置切换瞬间产生的日志。

set_max 是 pub(crate)，crate 里唯一的调用者是 Callsites::rebuild_interest：取所有 dispatcher 的 max_level_hint 的最大值，没给提示的按 TRACE 算。它在两种时候运行：Dispatch::new 创建新 dispatcher 时，和有人调用 rebuild_interest_cache 时（细节在 Callsite 与 Interest 缓存）。所以：

  • 一个 Dispatch 都没创建过时，MAX_LEVEL 是初值 OFF。上面程序的输出 current before any Dispatch = off 就是这个状态。
  • Dispatch::new(Show) 之后变成 info，来自 Show::max_level_hint 返回的 Some(LevelFilter::INFO)。
current before any Dispatch = off
current after Dispatch::new(Show) = info

宏那一侧，tracing 的 level_enabled! 把两道级别门连在一起：

macro_rules! level_enabled {
    ($lvl:expr) => {
        $lvl <= $crate::level_filters::STATIC_MAX_LEVEL
            && $lvl <= $crate::level_filters::LevelFilter::current()
    };
}

前一半是编译期常量 STATIC_MAX_LEVEL，由 max_level_* feature 决定；后一半就是 MAX_LEVEL。没有装 subscriber 的程序里 current() 是 OFF，所有宏在这里就停下，连调用点都不碰。两道门各自的代价和 feature 的合并规则在 级别的几道门。

📝NOTE
冷知识：全局 MAX_LEVEL 是为 rustc 加的

最初 tracing 只有每个调用点自己的 Interest 缓存，没有全局最大级别。PR #853（「core: add faster fast path for level filtering」）的说明写道：缓存建好之后跳过一个调用点只要「a single load and compare」，但建缓存本身要加锁注册调用点、再问 subscriber，「in batch-oriented programs and CLI tools that run to completion, the cost of building the initial cached value has a much bigger impact」；而「in rustc, it turns out that the cost of just building the callsite cache for the first time has a noticeable impact on performance」。

这个 PR 加了 Subscriber::max_level_hint 和全局 MAX_LEVEL，并把宏改成先查最大级别：「The macros have been updated to check the max level before anything requiring hitting the callsite cache or the subscriber TLS var.」本页 current() 里那个恒等转换也是这时写的（「such that it should hopefully be an identity conversion in release mode, rather than requiring rustc to generate a LUT」）。它没有照搬 log 的 set_max_level，理由是 tracing 允许多个 subscriber 同时存在，一个 subscriber 直接覆盖全局值会让另一个收不到它想要的级别，所以改成每个 subscriber 给提示、由 core 取最大值。CHANGELOG 记在 tracing-core 0.1.12。

从字符串解析

LevelFilter 和 Level 都实现了 FromStr，EnvFilter 解析 RUST_LOG 里的级别时用到它（EnvFilter）。impl FromStr for LevelFilter 先试数字、再试名字，名字不区分大小写：

    fn from_str(from: &str) -> Result<Self, Self::Err> {
        from.parse::<usize>()
            .ok()
            .and_then(|num| match num {
                0 => Some(LevelFilter::OFF),
                1 => Some(LevelFilter::ERROR),
                2 => Some(LevelFilter::WARN),
                3 => Some(LevelFilter::INFO),
                4 => Some(LevelFilter::DEBUG),
                5 => Some(LevelFilter::TRACE),
                _ => None,
            })
            .or_else(|| match from {
                // ...
            })
            .ok_or(ParseLevelFilterError(()))
    }

数字这里用的是对外的顺序（0 是 OFF，5 是 TRACE，和 log 的判别值一致），不是内部的 LevelInner 值。Level 的 FromStr 只接受 1 到 5，没有 OFF。

❗IMPORTANT
动脑筋："".parse::<LevelFilter>() 返回什么？

就是上面的程序（M2 Max、rustc 1.99.0），它对 ""、"0"、"3"、"Debug"、"verbose" 各解析一次。空字符串那一行打印的是 Err(...)，还是某个 Ok(LevelFilter::...)？如果是 Ok，是哪一级？

动脑筋答案

"".parse::<LevelFilter>() = Ok(LevelFilter::ERROR)
"0".parse::<LevelFilter>() = Ok(LevelFilter::OFF)
"3".parse::<LevelFilter>() = Ok(LevelFilter::INFO)
"Debug".parse::<LevelFilter>() = Ok(LevelFilter::DEBUG)
"verbose".parse::<LevelFilter>() = Err(ParseLevelFilterError(()))
"0".parse::<Level>() = Err("error parsing level: expected one of \"error\", \"warn\", \"info\", \"debug\", \"trace\", or a number 1-5")
"3".parse::<Level>() = Ok(Level(Info))

跑了 3 次，这几行相同。

  • "" 解析成 ERROR，不是错误。from_str 的 or_else 里第一条就是 "" => Some(LevelFilter::ERROR)（上面引用时省略的部分）。
  • "0" 是 OFF，"3" 是 INFO：走的是数字分支，按对外顺序编号。
  • "Debug" 能解析：名字用 eq_ignore_ascii_case 比较。
  • "verbose" 两个分支都不认，返回 ParseLevelFilterError。
  • Level 不接受 "0"，错误信息里写着「a number 1-5」。

小结

  • Metadata 描述一个调用点：name、target、level、位置、FieldSet、Kind。宏用 const fn new 把它放进 static META，和 static __CALLSITE 互相引用，运行时不构造。
  • Metadata<'a> 的 'a 是给 tracing-log 这类运行时来源留的；register_callsite 只收 'static 的，enabled 收任意生命周期的。
  • Level 对外「越详细越大」（TRACE 最大，与 log 一致），内部 Trace = 0、Error = 4，比较手写成对调两边，为的是让 LevelFilter::OFF（None）落在 niche 值 5 上、一次整数比较就能判断。
  • 全局 MAX_LEVEL 是 AtomicUsize，初值 OFF；LevelFilter::current() 用 Relaxed 读，release 构建里是恒等转换。它只在 Dispatch::new 和 rebuild_interest_cache 时被重算，取所有 dispatcher 的 max_level_hint 最大值，None 按 TRACE 算。
  • LevelFilter 解析：数字 0–5、名字不区分大小写，空字符串得到 ERROR。

💬 关联讨论

发起讨论
加载中...