Rust in Everything
基于 tracing-core 0.1.36

Callsite 与 Interest 缓存

主线位置：事件主线和 span 主线的第三道门。级别门（上一页）放行之后，宏读调用点里缓存的 Interest：never 到此为止，always 直接记录，sometimes 再去问当前 subscriber 的 enabled。缓存是第一次经过时建的，之后每次新建 Dispatch 或调用 rebuild_interest_cache 时整表重算。

stateDiagram-v2
  state "未注册，interest=0xFF" as Unregistered
  state "注册中" as Registering
  state "已注册" as Registered
  [*] --> Unregistered
  Unregistered --> Registering : CAS 抢到
  Registering --> Registering : 别的线程得 sometimes
  Registering --> Registered : set_interest 之后
  Registered --> Registered : rebuild 改写 interest

调用点（callsite）是源码里一个 info! / info_span! 所在的位置。宏在那里放一个 static，它做三件事：持有 Metadata；作为这个位置的唯一标识（Identifier）；缓存 subscriber 对它的兴趣，也就是 Interest。这一页讲第三件。代码几乎都在 tracing-core 的 callsite.rs，600 多行，其中一半是注释。Dispatch 本身（全局与线程局部、get_default）在 Dispatch：全局与线程局部，Subscriber 各方法的契约在 Subscriber trait。

Interest：三种回答

subscriber 在 register_callsite 里对每个调用点回答一个 Interest：

#[derive(Clone, Debug)]
pub struct Interest(InterestKind);

#[derive(Copy, Clone, Debug, Eq, PartialEq, Ord, PartialOrd)]
enum InterestKind {
    Never = 0,
    Sometimes = 1,
    Always = 2,
}
值subscriber 的意思宏经过这个调用点时
never这个调用点我永远不要跳过，连 enabled 都不问
sometimes要看情况（比如取决于当前在哪个 span 里）每次都调用当前 dispatcher 的 enabled
always这个调用点我永远要不问 enabled，直接构造事件分发

register_callsite 的默认实现是「enabled 为真就 always，否则 never」，也就是假设 enabled 只看元数据、每个调用点问一次就够。过滤条件随运行时上下文变化的 subscriber（比如 tracing-subscriber 里带 span 条件的 EnvFilter 指令，见 EnvFilter）要覆盖它、返回 sometimes。

宏那一侧，event! 的判断是：

        let enabled = $crate::level_enabled!($lvl) && {
            let interest = __CALLSITE.interest();
            !interest.is_never() && $crate::__macro_support::__is_enabled(__CALLSITE.metadata(), interest)
        };

__is_enabled：

    pub fn __is_enabled(meta: &Metadata<'static>, interest: Interest) -> bool {
        interest.is_always() || crate::dispatcher::get_default(|default| default.enabled(meta))
    }

__CALLSITE 的类型 MacroCallsite 就是 tracing-core 的 DefaultCallsite（pub use ... as MacroCallsite）。

Callsite trait 与 DefaultCallsite

Callsite 只要求两件事：

pub trait Callsite: Sync {
    fn set_interest(&self, interest: Interest);

    fn metadata(&self) -> &Metadata<'_>;

    // ...
    #[doc(hidden)]
    #[inline]
    fn private_type_id(&self, _: private::Private<()>) -> private::Private<TypeId>
    where
        Self: 'static,
    {
        private::Private(TypeId::of::<Self>())
    }
}

set_interest 只写不读：读缓存是每个实现自己的事。第三个方法 private_type_id 的参数和返回值都是 Private<T>，而 Private 的字段是 pub(crate)，crate 外的代码既构造不出参数、也写不出合法的返回值，所以没法覆盖它。注释说「THIS IS BY DESIGN」。它的唯一用途在下面的全局表里：可信地判断一个 &dyn Callsite 是不是 DefaultCallsite。

DefaultCallsite 是宏用的实现：

pub struct DefaultCallsite {
    interest: AtomicU8,
    registration: AtomicU8,
    meta: &'static Metadata<'static>,
    next: AtomicPtr<Self>,
}

两个原子字节分别记缓存的 Interest 和注册状态，next 是全局调用点链表的指针，就嵌在调用点自己身上。

一个字节编码 Interest

常量和 new：

    const UNREGISTERED: u8 = 0;
    const REGISTERING: u8 = 1;
    const REGISTERED: u8 = 2;

    const INTEREST_NEVER: u8 = 0;
    const INTEREST_SOMETIMES: u8 = 1;
    const INTEREST_ALWAYS: u8 = 2;

    /// Returns a new `DefaultCallsite` with the specified `Metadata`.
    pub const fn new(meta: &'static Metadata<'static>) -> Self {
        Self {
            interest: AtomicU8::new(0xFF),
            meta,
            next: AtomicPtr::new(ptr::null_mut()),
            registration: AtomicU8::new(Self::UNREGISTERED),
        }
    }

interest 的初值是 0xFF，不是三个合法值中的任何一个，表示「还不知道」。于是热路径 interest 只需要一次 Relaxed 读加一个 match：

    #[inline]
    pub fn interest(&'static self) -> Interest {
        match self.interest.load(Ordering::Relaxed) {
            Self::INTEREST_NEVER => Interest::never(),
            Self::INTEREST_SOMETIMES => Interest::sometimes(),
            Self::INTEREST_ALWAYS => Interest::always(),
            _ => self.register(),
        }
    }

interest 标 #[inline]，会被内联进每一个宏展开的地方；register 标 #[inline(never)] 和 #[cold]，注释是「This only happens once (or if the cached interest value was corrupted)」，让编译器把它挪出热路径，不把它的代码摊进每个调用点。写入在 set_interest，把 Interest 映射成 0 / 1 / 2 再 store。

实验：三种回答各让 enabled 被调用几次

一个计数用的 subscriber，register_callsite 依次回答 never、sometimes、always，每种情况打 1000 条 info!：

tracing = "=0.1.44"

use std::sync::atomic::{AtomicUsize, Ordering::Relaxed};

use tracing::span::{Attributes, Id, Record};
use tracing::subscriber::Interest;
use tracing::{Event, Metadata, Subscriber};

static REGISTER: AtomicUsize = AtomicUsize::new(0);
static ENABLED: AtomicUsize = AtomicUsize::new(0);
static EVENTS: AtomicUsize = AtomicUsize::new(0);

struct Counting {
  answer: &'static str,
}

impl Subscriber for Counting {
  fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest {
    REGISTER.fetch_add(1, Relaxed);
    match self.answer {
      "never" => Interest::never(),
      "sometimes" => Interest::sometimes(),
      _ => Interest::always(),
    }
  }
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    ENABLED.fetch_add(1, Relaxed);
    true
  }
  fn event(&self, _: &Event<'_>) {
    EVENTS.fetch_add(1, Relaxed);
  }
  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() {
  for answer in ["never", "sometimes", "always"] {
    REGISTER.store(0, Relaxed);
    ENABLED.store(0, Relaxed);
    EVENTS.store(0, Relaxed);
    // 每种回答用一个新 Dispatch，并且只在这一轮里当默认值
    tracing::subscriber::with_default(Counting { answer }, || {
      for i in 0..1000 {
        tracing::info!(i, "hello");
      }
    });
    println!(
      "{answer:<9}  register_callsite={}  enabled={}  event={}",
      REGISTER.load(Relaxed),
      ENABLED.load(Relaxed),
      EVENTS.load(Relaxed),
    );
  }
}

M2 Max、rustc 1.99.0，跑 3 次，输出相同：

never      register_callsite=1  enabled=0  event=0
sometimes  register_callsite=1  enabled=1000  event=1000
always     register_callsite=1  enabled=0  event=1000
  • never：1000 次都停在缓存上，enabled 和 event 都是 0。
  • sometimes：每次都问 enabled，1000 次。
  • always：一次也不问 enabled，1000 条事件全部送达。

三轮的 register_callsite 都是 1，但来历不同。第一轮是循环里第一条 info! 经过时注册调用点问的。后两轮调用点早已注册，这 1 次发生在 with_default 里的 Dispatch::new(Counting { .. })：新建 dispatcher 会把所有已注册的调用点重算一遍（下面的 rebuild_interest），上一轮的 dispatcher 已经 drop，所以只问了新的这一个。在 register_callsite 里打印一个「是否已进入循环」的标志可以看出来：第一轮是 in_loop=true，后两轮是 in_loop=false。

注册：三个状态和一次 CAS

DefaultCallsite::register：

    #[inline(never)]
    // This only happens once (or if the cached interest value was corrupted).
    #[cold]
    pub fn register(&'static self) -> Interest {
        // Attempt to advance the registration state to `REGISTERING`...
        match self.registration.compare_exchange(
            Self::UNREGISTERED,
            Self::REGISTERING,
            Ordering::AcqRel,
            Ordering::Acquire,
        ) {
            Ok(_) => {
                // Okay, we advanced the state, try to register the callsite.
                CALLSITES.push_default(self);
                rebuild_callsite_interest(self, &DISPATCHERS.rebuilder());
                self.registration.store(Self::REGISTERED, Ordering::Release);
            }
            // Great, the callsite is already registered! Just load its
            // previous cached interest.
            Err(Self::REGISTERED) => {}
            // Someone else is registering...
            Err(_state) => {
                debug_assert_eq!(
                    _state,
                    Self::REGISTERING,
                    "weird callsite registration state"
                );
                // Just hit `enabled` this time.
                return Interest::sometimes();
            }
        }

        match self.interest.load(Ordering::Relaxed) {
            Self::INTEREST_NEVER => Interest::never(),
            Self::INTEREST_ALWAYS => Interest::always(),
            _ => Interest::sometimes(),
        }
    }

compare_exchange 把 UNREGISTERED 换成 REGISTERING，三种结果：

  1. 抢到了（Ok）：这个线程负责注册。先把自己挂进全局调用点链表，再问 dispatcher 算出 Interest 写进 interest，最后把状态写成 REGISTERED。
  2. 已经是 REGISTERED：别人早注册完了。走到这里，说明这个线程读 interest 时还是 0xFF、但 CAS 时状态已经是 REGISTERED，比如两次读之间别的线程刚刚完成注册。直接读缓存返回。
  3. 是 REGISTERING：另一个线程正在注册。不等它，直接返回 sometimes，「Just hit enabled this time」。

所以计划里「别的线程正在注册时返回 sometimes」是对的，但窗口比「正在注册」更窄：注册线程在 rebuild_callsite_interest 里调用 set_interest 之后，interest 字节就不再是 0xFF，其他线程从热路径 interest() 直接拿到缓存，根本不进 register，哪怕 registration 还没写成 REGISTERED。只有在 CAS 成功到 set_interest 之间到达的线程才拿到这个临时的 sometimes，而这段时间主要花在各个 dispatcher 的 register_callsite 上。

实验：两个线程同时第一次经过

让 register_callsite 睡 200ms，把这个窗口拉长；t2 比 t1 晚 50ms 出发，各自经过同一个调用点两次，中间隔 300ms：

tracing = "=0.1.44"

use std::sync::{Arc, Barrier};
use std::thread;
use std::time::Duration;

use tracing::span::{Attributes, Id, Record};
use tracing::subscriber::Interest;
use tracing::{Event, Metadata, Subscriber};

fn who() -> String {
  thread::current().name().unwrap_or("?").to_string()
}

struct Slow;

impl Subscriber for Slow {
  fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest {
    println!("[{}] register_callsite({}) 开始，睡 200ms", who(), meta.name());
    thread::sleep(Duration::from_millis(200));
    println!("[{}] register_callsite 返回 always", who());
    Interest::always()
  }
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    println!("[{}] enabled", who());
    true
  }
  fn event(&self, _: &Event<'_>) {
    println!("[{}] event", who());
  }
  // new_span、record、record_follows_from、enter、exit 同上一个程序
  // ...
}

fn work() {
  tracing::info!("hit");
}

fn main() {
  tracing::subscriber::set_global_default(Slow).unwrap();
  let barrier = Arc::new(Barrier::new(2));
  let handles: Vec<_> = ["t1", "t2"]
    .into_iter()
    .enumerate()
    .map(|(n, name)| {
      let barrier = barrier.clone();
      thread::Builder::new()
        .name(name.into())
        .spawn(move || {
          barrier.wait();
          // t2 晚 50ms 出发，保证 t1 先抢到 REGISTERING
          thread::sleep(Duration::from_millis(50 * n as u64));
          work();
          thread::sleep(Duration::from_millis(300));
          work();
        })
        .unwrap()
    })
    .collect();
  for h in handles {
    h.join().unwrap();
  }
}

跑 3 次，输出相同：

[t1] register_callsite(event src/bin/race.rs:39) 开始，睡 200ms
[t2] enabled
[t2] event
[t1] register_callsite 返回 always
[t1] event
[t2] event
[t1] event
  • t1 抢到 CAS，进入 register_callsite。
  • 50ms 后 t2 到达：interest 还是 0xFF，进 register，CAS 失败、状态是 REGISTERING，拿到 sometimes，于是调用了一次 enabled。它没有等 t1，事件在 t1 注册完之前就送达了。
  • t1 拿到 always 后不再问 enabled；两个线程的第二次经过都读到缓存的 always，也不问。
  • register_callsite 只被调用了一次。
📝NOTE
没有蠢问题

问： 注册还没完成，t2 就按 sometimes 处理了。万一 subscriber 最后对这个调用点回答的是 never，t2 的那条事件是不是漏出去了？

答： 不会。sometimes 的意思是「去问 enabled」，而 enabled 才是 subscriber 对「这一次要不要」的正式回答，register_callsite 返回的 Interest 只是对它的缓存。一个 register_callsite 说 never 的调用点，enabled 本来就应该返回 false（默认实现正是用 enabled 推出 Interest 的）。所以临时的 sometimes 只多花一次 enabled 调用，不改变结果。反过来，如果 t2 选择等待，就要自旋或阻塞，等一个可能任意慢的 register_callsite。

全局调用点表：无锁链表与 LOCKED_CALLSITES

注册过的调用点都要记下来，以后 dispatcher 变了才能逐个重算。Callsites 和它旁边的几个 static：

static CALLSITES: Callsites = Callsites {
    list_head: AtomicPtr::new(ptr::null_mut()),
    has_locked_callsites: AtomicBool::new(false),
};

static DISPATCHERS: Dispatchers = Dispatchers::new();

static LOCKED_CALLSITES: Lazy<Mutex<Vec<&'static dyn Callsite>>> = Lazy::new(Default::default);

struct Callsites {
    list_head: AtomicPtr<DefaultCallsite>,
    has_locked_callsites: AtomicBool,
}

表分两半。DefaultCallsite 自带 next 指针，进一条侵入式的无锁单链表；其他 Callsite 实现没有地方放指针，进 LOCKED_CALLSITES，一个 Mutex<Vec<...>>。公开函数 callsite::register 就靠上面的 private_type_id 分流：

pub fn register(callsite: &'static dyn Callsite) {
    // Is this a `DefaultCallsite`? If so, use the fancy linked list!
    if callsite.private_type_id(private::Private(())).0 == TypeId::of::<DefaultCallsite>() {
        let callsite = unsafe {
            // ...
            &*(callsite as *const dyn Callsite as *const DefaultCallsite)
        };
        CALLSITES.push_default(callsite);
    } else {
        CALLSITES.push_dyn(callsite);
    }

    rebuild_callsite_interest(callsite, &DISPATCHERS.rebuilder());
}

指针转换的安全性依赖 private_type_id 不可被覆盖：外部实现没法谎报自己是 DefaultCallsite。

push_default 是标准的 CAS 头插：

    fn push_default(&self, callsite: &'static DefaultCallsite) {
        let mut head = self.list_head.load(Ordering::Acquire);

        loop {
            callsite.next.store(head, Ordering::Release);

            assert_ne!(
                callsite as *const _, head,
                "Attempted to register a `DefaultCallsite` that already exists! \
                // ...
            );

            match self.list_head.compare_exchange(
                head,
                callsite as *const _ as *mut _,
                Ordering::AcqRel,
                Ordering::Acquire,
            ) {
                Ok(_) => {
                    break;
                }
                Err(current) => head = current,
            }
        }
    }

能做成这么简单的无锁链表，是因为它只增不删：调用点是 'static，永远不会注销，也就没有 ABA 和内存回收的问题。assert_ne! 防的是同一个调用点被头插两次：那样它的 next 会指向自己，遍历时死循环。DefaultCallsite::register 有状态机保证只插一次；直接对一个 DefaultCallsite 调用公开的 callsite::register 则没有这层保护，所以文档建议用前者。这个断言只能抓到「重复的调用点正好是表头」的情况。

push_dyn 加锁、推进 Vec，并把 has_locked_callsites 置为 true。for_each 先沿链表走一遍，再看这个标志，只有真的有自定义调用点时才去锁 LOCKED_CALLSITES。头插意味着遍历顺序是「后注册的先访问」。

用到 LOCKED_CALLSITES 的实际例子：tracing-log 开了 interest-cache feature 后，会用 callsite::register 注册一个 SentinelCallsite。它不产生任何日志，set_interest 里只把一个计数器加一：每次重算缓存都会调用所有调用点的 set_interest，tracing-log 借此得知「过滤配置变了」，清空自己给 log 记录做的缓存。

📝NOTE
冷知识：无锁链表是 0.1.27 才有的

在 tracing-core 0.1.27 之前，0.1 线的调用点表只有 Mutex<Vec<&'static dyn Callsite>>。PR #2083（「core: add a limited form of the linked-list callsite registry for v0.1.x」）列了它的问题：每注册一个调用点都要加锁，「This can cause a deadlock when a register_callsite implementation calls into code that also registers a callsite」；两个线程注册毫不相干的调用点也要互相等；持锁时可能分配内存，让 tracing 很难用在内存分配器里。

master（0.2）分支早已换成侵入式链表，但那需要给 Callsite trait 加一个取链表节点的方法，在 0.1 上是破坏性改动。于是这个 PR 新增了 DefaultCallsite 类型，自带链表节点，tracing 的宏改用它，Mutex<Vec> 只留给自定义的 Callsite，也就是本页的两半结构。同一个 PR 还把 dispatcher 表改成「只有一个 subscriber 时不加锁」：「When there's only a global default subscriber, we can once again avoid locking for the registry of subscribers.」这就是下一节的 has_just_one。CHANGELOG 记在 tracing-core 0.1.27：「DefaultCallsite, a pre-written Callsite implementation for use in instrumentation crates」。

重算：rebuild_interest 与 MAX_LEVEL

dispatcher 表

重算要知道「现在有哪些 dispatcher」。这张表在 dispatchers 子模块里（std 版本）：

    pub(super) struct Dispatchers {
        has_just_one: AtomicBool,
    }

    static LOCKED_DISPATCHERS: Lazy<RwLock<Vec<dispatcher::Registrar>>> =
        Lazy::new(Default::default);

    pub(super) enum Rebuilder<'a> {
        JustOne,
        Read(RwLockReadGuard<'a, Vec<dispatcher::Registrar>>),
        Write(RwLockWriteGuard<'a, Vec<dispatcher::Registrar>>),
    }

Registrar 是 Dispatch 的弱引用：表不让 subscriber 多活一刻，subscriber drop 之后，对应的 Registrar 升级失败，遍历时被 Rebuilder::for_each 的 filter_map(dispatcher::Registrar::upgrade) 跳过：

        pub(super) fn for_each(&self, mut f: impl FnMut(&dispatcher::Dispatch)) {
            let iter = match self {
                Rebuilder::JustOne => {
                    dispatcher::get_default(f);
                    return;
                }
                Rebuilder::Read(vec) => vec.iter(),
                Rebuilder::Write(vec) => vec.iter(),
            };
            iter.filter_map(dispatcher::Registrar::upgrade)
                .for_each(|dispatch| f(&dispatch))
        }

三种 Rebuilder：

变体什么时候遍历谁
WriteDispatch::new 登记新 dispatcher 时，拿着写锁表里所有还活着的 dispatcher
Read平时（注册调用点、rebuild_interest_cache），最近一次登记后表里多于一个同上，拿读锁
JustOne平时，has_just_one 为真（最近一次登记后表里至多一个）不看表，只问当前线程的 get_default

rebuilder 在 has_just_one 为真时直接返回 JustOne，一把锁都不碰。最后一行的「只问当前线程」有一个后果，放在本页最后的动脑筋里。

Dispatch::new 触发整表重算

登记 dispatcher 的入口是 Dispatch::new：

    pub fn new<S>(subscriber: S) -> Self
    where
        S: Subscriber + Send + Sync + 'static,
    {
        let me = Dispatch {
            subscriber: Kind::Scoped(Arc::new(subscriber)),
        };
        callsite::register_dispatch(&me);
        me
    }

注意是创建 Dispatch 时，不是 set_global_default、set_default、with_default 把它装上时。tracing 门面的 tracing::subscriber::with_default(sub, f) 和 set_global_default(sub) 内部都先 Dispatch::new(sub)，所以看上去像「装上时重算」。register_dispatch：

pub(crate) fn register_dispatch(dispatch: &Dispatch) {
    let dispatchers = DISPATCHERS.register_dispatch(dispatch);
    dispatch.subscriber().on_register_dispatch(dispatch);
    CALLSITES.rebuild_interest(dispatchers);
}

Dispatchers::register_dispatch 拿写锁，先 retain 掉已经死掉的 Registrar，推进新的，再把 has_just_one 设成 dispatchers.len() <= 1，把写锁守卫作为 Rebuilder::Write 交出去。重算全程持有写锁；这时 has_just_one 若为假，其他线程注册调用点要拿读锁，会等它重算完。

rebuild_interest

Callsites::rebuild_interest：

    fn rebuild_interest(&self, dispatchers: dispatchers::Rebuilder<'_>) {
        let mut max_level = LevelFilter::OFF;
        dispatchers.for_each(|dispatch| {
            // If the subscriber did not provide a max level hint, assume
            // that it may enable every level.
            let level_hint = dispatch.max_level_hint().unwrap_or(LevelFilter::TRACE);
            if level_hint > max_level {
                max_level = level_hint;
            }
        });

        self.for_each(|callsite| {
            rebuild_callsite_interest(callsite, &dispatchers);
        });
        LevelFilter::set_max(max_level);
    }

三步：从 OFF 起，取所有 dispatcher 的 max_level_hint 的最大值，没给提示的按 TRACE 算；对表里每个调用点重算 Interest；最后写全局 MAX_LEVEL（上一页）。set_max 在 tracing-core 里只有这一个调用者，所以 LevelFilter::current() 也只在这两种时候变化。

每个调用点的重算在 rebuild_callsite_interest：

fn rebuild_callsite_interest(
    callsite: &'static dyn Callsite,
    dispatchers: &dispatchers::Rebuilder<'_>,
) {
    let meta = callsite.metadata();

    let mut interest = None;
    dispatchers.for_each(|dispatch| {
        let this_interest = dispatch.register_callsite(meta);
        interest = match interest.take() {
            None => Some(this_interest),
            Some(that_interest) => Some(that_interest.and(this_interest)),
        }
    });

    let interest = interest.unwrap_or_else(Interest::never);
    callsite.set_interest(interest)
}

每个 dispatcher 的 register_callsite 都被调用一次，结果用 Interest::and 两两合并；表里一个活着的 dispatcher 都没有时是 never。and 的规则只有一条，相同就保留，不同就是 sometimes：

    pub(crate) fn and(self, rhs: Interest) -> Self {
        if self.0 == rhs.0 {
            self
        } else {
            Interest::sometimes()
        }
    }
A 说B 说缓存宏的行为
nevernevernever跳过
alwaysalwaysalways直接分发给当前 dispatcher
neveralwayssometimes问当前 dispatcher 的 enabled
任一sometimessometimes同上

缓存是全进程共享的，而宏实际分发给的是当前线程的 dispatcher（Dispatch：全局与线程局部）。两个 dispatcher 意见不同时，只有 sometimes 能让每个线程的事件由它自己的 dispatcher 决定。Interest::always() 的文档注释仍写着「If any subscriber expresses that it is always() interested in a given callsite, then the callsite will always be enabled」，那是旧规则，代码已经不是这样。

📝NOTE
冷知识：「谁说 always 就听谁的」是 0.1.15 改掉的

PR #927（「core: change Interest-combining to play nicer with multiple subscribers」）之前，合并规则是：「If any subscriber returns Interest::always for a callsite, that interest currently takes priority over any other Interests.」后果是：「if two threads have separate subscribers, one of which enables a callsite always, and the other never, both subscribers will always record that callsite, without the option to disable it.」问题报告在 issue #902（「Filter leak when using WithSubscriber」）。

改动之后，「always is only returned if both Interests are always. If only one is always, the combined interest is now sometimes, instead.」也就是上面的 and。PR 还顺带修了 EnvFilter：它原先假设对 span 只会走 register_callsite、不会被问 enabled，新规则下这个假设不再成立。CHANGELOG 记在 tracing-core 0.1.15：「When combining Interest from multiple subscribers, if the interests differ, the current subscriber is now always asked if a callsite should be enabled」。

实验：第二个 dispatcher 带来的重算

两个会打印每个回调的 subscriber：A 只要 WARN 及以上，B 什么都要。A 装成全局默认，B 只在 with_default 里用：

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

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

/// name 是 "A" 或 "B"；max 是它要的最详细级别
struct Loud {
  name: &'static str,
  max: Level,
}

impl Subscriber for Loud {
  fn max_level_hint(&self) -> Option<LevelFilter> {
    println!("  {}.max_level_hint -> {}", self.name, self.max);
    Some(LevelFilter::from_level(self.max))
  }
  fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest {
    let interest = if *meta.level() <= self.max { Interest::always() } else { Interest::never() };
    println!("  {}.register_callsite({}) -> {:?}", self.name, meta.level(), interest);
    interest
  }
  fn enabled(&self, meta: &Metadata<'_>) -> bool {
    let yes = *meta.level() <= self.max;
    println!("  {}.enabled({}) -> {}", self.name, meta.level(), yes);
    yes
  }
  fn event(&self, event: &Event<'_>) {
    println!("  {}.event({})", self.name, event.metadata().level());
  }
  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) {}
}

impl Drop for Loud {
  fn drop(&mut self) {
    println!("  {} dropped", self.name);
  }
}

fn work() {
  tracing::info!("info");
  tracing::warn!("warn");
}

fn step(s: &str) {
  println!("{s}");
}

fn main() {
  step("1. Dispatch::new(A) + set_global_default");
  let a = Dispatch::new(Loud { name: "A", max: Level::WARN });
  dispatcher::set_global_default(a).unwrap();
  println!("  current = {}", LevelFilter::current());

  step("2. work()");
  work();

  step("3. Dispatch::new(B)");
  let b = Dispatch::new(Loud { name: "B", max: Level::TRACE });
  println!("  current = {}", LevelFilter::current());

  step("4. with_default(&b, work)");
  dispatcher::with_default(&b, work);

  step("5. work() on global A");
  work();

  step("6. drop(b)");
  drop(b);
  println!("  current = {}", LevelFilter::current());
  work();

  step("7. rebuild_interest_cache()");
  callsite::rebuild_interest_cache();
  println!("  current = {}", LevelFilter::current());
  work();
}

跑 3 次，输出相同：

1. Dispatch::new(A) + set_global_default
  A.max_level_hint -> WARN
  current = warn
2. work()
  A.register_callsite(WARN) -> Interest(Always)
  A.event(WARN)
3. Dispatch::new(B)
  A.max_level_hint -> WARN
  B.max_level_hint -> TRACE
  A.register_callsite(WARN) -> Interest(Always)
  B.register_callsite(WARN) -> Interest(Always)
  current = trace
4. with_default(&b, work)
  A.register_callsite(INFO) -> Interest(Never)
  B.register_callsite(INFO) -> Interest(Always)
  B.enabled(INFO) -> true
  B.event(INFO)
  B.event(WARN)
5. work() on global A
  A.enabled(INFO) -> false
  A.event(WARN)
6. drop(b)
  B dropped
  current = trace
  A.enabled(INFO) -> false
  A.event(WARN)
7. rebuild_interest_cache()
  A.max_level_hint -> WARN
  A.register_callsite(INFO) -> Interest(Never)
  A.register_callsite(WARN) -> Interest(Always)
  current = warn
  A.event(WARN)

逐步看：

  1. Dispatch::new(A) 重算：只问了 max_level_hint，因为表里还没有调用点。MAX_LEVEL 变成 warn。
  2. info! 在级别门就被挡住（INFO > WARN），它的调用点没有注册；warn! 注册，问 A，得到 always。
  3. Dispatch::new(B)，还没装到任何地方，重算就发生了：先问两个 dispatcher 的 max_level_hint，再对表里唯一的调用点（warn!）问两者的 register_callsite。MAX_LEVEL 变成 trace。
  4. with_default 本身没有触发任何回调。info! 现在过了级别门，第一次注册：表里有两个 dispatcher，走 Read，A 说 never、B 说 always，合并成 sometimes，于是问当前线程的 dispatcher（B）的 enabled。warn! 是 always，直接给 B。
  5. 回到全局的 A：info! 的缓存是 sometimes，问 A.enabled，得到 false，事件被丢掉。B 的存在让 A 的线程每次都多一次 enabled 调用。
  6. drop(b) 之后 B 被释放，但什么都没有重算：MAX_LEVEL 还是 trace，info! 还是 sometimes。tracing-core 没有在 Dispatch drop 时重算的代码。给 DefaultGuard 的 drop 加上重算的 PR #3530（「core: rebuild interest cache when dropping default Dispatch」）写作时还没有合并，它的说明也写着「that won't happen until another Dispatch is created or rebuild_interest_cache is called by the application code」。模块文档说「when a subscriber is dropped, the interest cache is also re-evaluated」，和 0.1.36 的代码不符。
  7. 手动 rebuild_interest_cache()：B 的 Registrar 升级失败被跳过，只问 A。info! 回到 never，MAX_LEVEL 回到 warn，info! 又在级别门被挡住，连 enabled 都不问了。两个调用点按 INFO、WARN 的顺序被访问，后注册的先访问，正是链表头插的结果。

谁会调用 rebuild_interest_cache

公开函数 rebuild_interest_cache 只有一行，CALLSITES.rebuild_interest(DISPATCHERS.rebuilder())。它给「过滤配置会变、但很少变」的 subscriber 用：平时 register_callsite 照样回答 always / never 享受缓存，配置变了调用它一次。max_level_hint 会变的 subscriber 必须在变化后调用它，否则 MAX_LEVEL 不更新。tracing-subscriber 里调用它的是 reload：Handle::modify 改完 layer、放掉锁之后调用一次（reload 与运行时改级别）。代价和调用点数量成正比，每个调用点都要把每个 dispatcher 的 register_callsite 问一遍。

JustOne：只有一个 dispatcher 时的捷径

回到 Rebuilder::JustOne。最近一次登记后表里至多一个 dispatcher 时，注册调用点和 rebuild_interest_cache 都不加锁，改为 dispatcher::get_default(f)，问当前线程的默认 dispatcher。只装一个全局 subscriber 的常见程序里，这和「问表里那一个」是同一件事，而且省掉了读锁。

可如果那唯一的 dispatcher 只是某个线程的局部默认值，另一个线程上的 get_default 拿到的是 NoSubscriber，它的 register_callsite 永远回答 never。

❗IMPORTANT
动脑筋：主线程 set_default 之后，另一个线程先经过调用点，主线程再经过 3 次，subscriber 收到几条事件？

平台 M2 Max、rustc 1.99.0。整个进程只创建了这一个 Dispatch，没有设全局默认值。

tracing = "=0.1.44"

use std::sync::atomic::{AtomicUsize, Ordering::Relaxed};
use std::thread;

use tracing::span::{Attributes, Id, Record};
use tracing::{Event, Metadata, Subscriber};

static EVENTS: AtomicUsize = AtomicUsize::new(0);

struct Count;

impl Subscriber for Count {
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    true
  }
  fn event(&self, _: &Event<'_>) {
    EVENTS.fetch_add(1, Relaxed);
  }
  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 work() {
  tracing::info!("hello");
}

fn main() {
  // 只在主线程设默认 subscriber，不设全局的
  let _guard = tracing::subscriber::set_default(Count);
  // 另一个线程先经过这个调用点
  thread::spawn(work).join().unwrap();
  // 主线程再经过 3 次
  for _ in 0..3 {
    work();
  }
  println!("events = {}", EVENTS.load(Relaxed));
}

动脑筋答案

events = 0

跑了 3 次，都是 0。一条都没有：

  • set_default(Count) 内部先 Dispatch::new(Count)：表里只有它一个，has_just_one 为真；Count 没有 max_level_hint，按 TRACE 算，MAX_LEVEL 是 trace。
  • 子线程经过 info!：级别门放行，调用点第一次注册。rebuilder() 返回 JustOne，for_each 调用子线程的 get_default，那里没有默认值，拿到的是 NoSubscriber，回答 never。never 被写进全进程共享的 interest 字节。子线程本身没有 subscriber，这条丢了是应该的。
  • 主线程的 3 次：interest() 读到 never，直接跳过，Count 永远没机会被问。

把 set_default 换成 set_global_default(Count)，同一个程序打印 events = 4：所有线程的 get_default 都落到全局的 Count 上。这个行为有两个仍然开着的 issue：#2874（「Incorrect Interest::Never is cached and never invalidated on v0.1」，先创建 Dispatch 但不装、经过调用点、再 with_default）和 #3611（「has_just_one callsite short-path caches Interest::Never when a subscriber-less thread first registers the callsite」，就是这里的情形，修复它的 PR #3614 写作时也还没合并）。在测试里用 with_default / set_default 捕获日志、同时别的线程也在打日志时，会碰到它。

小结

  • Interest 有三个值：never 跳过，always 直接分发，sometimes 每次问当前 dispatcher 的 enabled。缓存它是为了让大多数调用点不用每次问 subscriber。
  • DefaultCallsite 用一个 AtomicU8 存 Interest（0 / 1 / 2，初值 0xFF 表示未知），热路径是一次 Relaxed 读；另一个 AtomicU8 是注册状态 UNREGISTERED → REGISTERING → REGISTERED。
  • 注册靠一次 CAS：抢到的线程挂链表、问 dispatcher、写缓存；遇到 REGISTERING 的线程不等，返回 sometimes 去问 enabled。set_interest 之后其他线程就直接读到缓存了。
  • 全局调用点表分两半：DefaultCallsite 进只增不删的无锁头插链表，其他 Callsite 进 LOCKED_CALLSITES（Mutex<Vec>），靠无法覆盖的 private_type_id 区分。
  • 每个 dispatcher 的 register_callsite 都参与合并，and 的规则是相同保留、不同变 sometimes（0.1.15 起）。
  • rebuild_interest 取所有活着的 dispatcher 的 max_level_hint 最大值（None 当 TRACE）写进 MAX_LEVEL，再逐个调用点重算。它在 Dispatch::new 时和 rebuild_interest_cache() 时运行；装上、with_default、drop 一个 Dispatch 都不会触发。
  • 表里只有一个 dispatcher 时走 JustOne，按当前线程的默认值注册调用点；那个 dispatcher 只是某线程的局部默认值时，别的线程会给调用点缓存上 never。

💬 关联讨论

发起讨论
加载中...