Rust in Everything
基于 tracing-core 0.1.36

Dispatch:全局与线程局部

主线位置:两条主线都经过这里。事件主线的第四道门 __is_enabled 和最后的 Event::dispatch 都调用 dispatcher::get_default,由它决定这条事件交给哪个 subscriber。span 主线只在创建时问一次:Span::new 用 get_default 拿到当前 Dispatch,克隆一份存进 span 自己,之后的 enter、exit、clone、drop 都直接找这份,不再查默认值。

flowchart TB
  start["get_default(f)"] --> cnt{"SCOPED_COUNT == 0 ?"}
  cnt -->|是| glob["get_global()"]
  cnt -->|否| tls["CURRENT_STATE.try_with"]
  tls -->|线程局部已销毁| none1["f(NONE)"]
  tls --> canenter{"can_enter ?"}
  canenter -->|false| none2["f(NONE)"]
  canenter -->|true| cur["Entered::current()"]
  cur -->|有线程默认| scoped["线程默认 Dispatch"]
  cur -->|None| glob
  glob --> inited{"GLOBAL_INIT == INITIALIZED ?"}
  inited -->|是| gd["GLOBAL_DISPATCH"]
  inited -->|否| none3["NONE:NoSubscriber"]

tracing 的宏不知道你装的是 fmt、Registry 还是自己写的 subscriber,它只问一句「现在该交给谁」。回答这句话的是 dispatcher.rs:一个全局默认、每个线程一个可选的线程默认、一套守卫和计数器。本页讲这套机制;subscriber 本身有哪些方法见 Subscriber trait,新 dispatcher 装上后怎么重算调用点缓存见 Callsite 与 Interest 缓存。

tracing 门面的 tracing::subscriber::{set_global_default, set_default, with_default} 只是先 Dispatch::new(subscriber) 再转给这里的同名函数(tracing/src/subscriber.rs),下文直接讲 tracing-core 里的版本。

Dispatch 是什么

Dispatch 只有一个字段,类型是私有的 Kind:

#[derive(Clone)]
pub struct Dispatch {
    subscriber: Kind<Arc<dyn Subscriber + Send + Sync>>,
}

#[derive(Clone)]
pub struct WeakDispatch {
    subscriber: Kind<Weak<dyn Subscriber + Send + Sync>>,
}

#[derive(Clone)]
enum Kind<T> {
    Global(&'static (dyn Subscriber + Send + Sync)),
    Scoped(T),
}
变体谁会是这种clone 的代价
Kind::Scoped(Arc<..>)Dispatch::new(sub) 新建的,包括 set_default 用的一次 Arc 引用计数加一
Kind::Global(&'static ..)装成全局默认之后的那个;Dispatch::none()复制一个胖指针

Dispatch::new 要求 S: Subscriber + Send + Sync + 'static,因为同一个 Dispatch 会被克隆进 span、被别的线程拿去用。它在返回前调用 callsite::register_dispatch(&me):把自己登记进 dispatcher 列表,调用 subscriber 的 on_register_dispatch,然后重算所有调用点的 Interest。所以新建一个 Dispatch 就会影响全体调用点的缓存,不需要等它被设成默认(细节见 Callsite 与 Interest 缓存)。

「没有 subscriber」也是一个 Dispatch。文件里有三个 static:

static mut GLOBAL_DISPATCH: Dispatch = Dispatch {
    subscriber: Kind::Global(&NO_SUBSCRIBER),
};
static NONE: Dispatch = Dispatch {
    subscriber: Kind::Global(&NO_SUBSCRIBER),
};
static NO_SUBSCRIBER: NoSubscriber = NoSubscriber::new();

NONE 是所有「找不到」分支的返回值,指向零大小的 NoSubscriber。因为是 &'static,拿到它不分配、不改引用计数。

set_global_default:只能设一次

set_global_default 用一个三态的 GLOBAL_INIT 做一次性初始化:

static EXISTS: AtomicBool = AtomicBool::new(false);
static GLOBAL_INIT: AtomicUsize = AtomicUsize::new(UNINITIALIZED);

const UNINITIALIZED: usize = 0;
const INITIALIZING: usize = 1;
const INITIALIZED: usize = 2;
pub fn set_global_default(dispatcher: Dispatch) -> Result<(), SetGlobalDefaultError> {
    // if `compare_exchange` returns Result::Ok(_), then `new` has been set and
    // `current`—now the prior value—has been returned in the `Ok()` branch.
    if GLOBAL_INIT
        .compare_exchange(
            UNINITIALIZED,
            INITIALIZING,
            Ordering::SeqCst,
            Ordering::SeqCst,
        )
        .is_ok()
    {
        let subscriber = {
            let subscriber = match dispatcher.subscriber {
                Kind::Global(s) => s,
                Kind::Scoped(s) => unsafe {
                    // safety: this leaks the subscriber onto the heap. the
                    // reference count will always be at least 1, because the
                    // global default will never be dropped.
                    &*Arc::into_raw(s)
                },
            };
            Kind::Global(subscriber)
        };
        unsafe {
            GLOBAL_DISPATCH = Dispatch { subscriber };
        }
        GLOBAL_INIT.store(INITIALIZED, Ordering::SeqCst);
        EXISTS.store(true, Ordering::Release);
        Ok(())
    } else {
        Err(SetGlobalDefaultError { _no_construct: () })
    }
}
  • 谁赢:compare_exchange(UNINITIALIZED, INITIALIZING) 只有一个线程能成功。成功的线程写 GLOBAL_DISPATCH,最后才把状态改成 INITIALIZED。失败的线程(不管对方是正在写还是已经写完)立刻得到 Err,不等待。
  • 读的一侧:get_global 先看 GLOBAL_INIT 是否等于 INITIALIZED,不是就返回 &NONE。所以 INITIALIZING 期间读到的是「没有 subscriber」,不会读到写了一半的 static mut。
  • 怎么变成 &'static:Arc::into_raw 交出这个 Arc 的那一份引用计数,再也不会有人把它减回去,subscriber 从此不会被释放。这是有意的泄漏,注释说得很清楚。不是 Box::leak:堆上的对象还是原来那个 ArcInner,别处克隆的 Dispatch 仍然指向它。
  • EXISTS:只增不减的「曾经设过 dispatcher」标志,set_default 也会把它置成 true。tracing 的 log feature 靠 has_been_set() 读它,决定要不要把事件转发给 log(见 和 log 互通)。

失败时的错误类型 SetGlobalDefaultError 带一个私有的 _no_construct: (),外面造不出来。Display 和 Debug 用同一句话 MESSAGE。

下面的程序都用同一个小 subscriber:收到事件就打印自己的名字、线程名和消息,被 drop 时也打印一行。

[dependencies]
tracing = "=0.1.44"
use std::fmt;
use tracing::field::Field;
use tracing::span::{Attributes, Id, Record};
use tracing::{Event, Metadata, Subscriber};

/// 把收到的每条事件连同自己的名字、所在线程打印出来。
pub struct Named(pub &'static str);

impl Subscriber for Named {
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    true
  }
  fn new_span(&self, _: &Attributes<'_>) -> Id {
    Id::from_u64(1)
  }
  fn record(&self, _: &Id, _: &Record<'_>) {}
  fn record_follows_from(&self, _: &Id, _: &Id) {}
  fn event(&self, event: &Event<'_>) {
    let mut msg = String::new();
    event.record(&mut |f: &Field, v: &dyn fmt::Debug| {
      if f.name() == "message" {
        msg = format!("{v:?}");
      }
    });
    let thread = std::thread::current();
    println!("  [{}] 线程 {}:{}", self.0, thread.name().unwrap_or("?"), msg);
  }
  fn enter(&self, _: &Id) {}
  fn exit(&self, _: &Id) {}
}

impl Drop for Named {
  fn drop(&mut self) {
    println!("  ({} 被 drop)", self.0);
  }
}

先设两次全局默认,再用 tracing-subscriber 的 fmt().try_init() 设第三次(这一段要加 tracing-subscriber = { version = "=0.3.23", default-features = false, features = ["fmt", "std"] }):

use tracing::info;

fn main() {
  let first = tracing::subscriber::set_global_default(Named("first"));
  println!("第一次:{first:?}");
  let err = tracing::subscriber::set_global_default(Named("second")).unwrap_err();
  println!("第二次 Display:{err}");
  println!("第二次 Debug:{err:?}");
  let err = tracing_subscriber::fmt().try_init().unwrap_err();
  println!("fmt().try_init() Display:{err}");
  println!("fmt().try_init() Debug:{err:?}");
  info!("谁收到这条?");
}

M2 Max、rustc 1.99.0、--release,连跑 3 次输出相同:

第一次:Ok(())
  (second 被 drop)
第二次 Display:a global default trace dispatcher has already been set
第二次 Debug:SetGlobalDefaultError("a global default trace dispatcher has already been set")
fmt().try_init() Display:a global default trace dispatcher has already been set
fmt().try_init() Debug:SetGlobalDefaultError("a global default trace dispatcher has already been set")
  [first] 线程 main:谁收到这条?
  • 第二次失败时,传进来的 Dispatch 随 dispatcher 参数一起被 drop,second 立刻析构。全局默认还是 first。
  • fmt().try_init() 返回 Box<dyn Error>,里面是 tracing-subscriber 的 TryInitError。try_init 第一步就是 set_global_default,TryInitError 的 Display 和 Debug 又原样转给里面装着的错误,所以看到的还是同一句话。init() 就是 try_init().expect(..),两次 init 的报错见常见坑一章。
📝NOTE
冷知识:unwrap() 曾经只告诉你 _no_construct: ()

tracing-core 0.1.29 之前,SetGlobalDefaultError 的 Debug 是 #[derive] 出来的。PR #2250 的描述写道:派生的 Debug 输出「just looks like this: SetGlobalDefaultError { _no_construct: () } which isn't particularly helpful」,而 unwrap() / expect() 用的偏偏是 Debug,不是 Display。修法是手写 Debug,用 debug_tuple 把 MESSAGE 当成唯一字段打印,于是有了上面输出里的 SetGlobalDefaultError("a global default trace dispatcher has already been set")。这个改动随 tracing-core 0.1.29 发布,CHANGELOG 记作「Fixed unhelpful fmt::Debug output for dispatcher::SetGlobalDefaultError」。

set_default 与 DefaultGuard:线程局部的默认值

线程默认存在 CURRENT_STATE 里:

std::thread_local! {
    static CURRENT_STATE: State = const {
        State {
            default: RefCell::new(None),
            can_enter: Cell::new(true),
        }
    };
}

#[cfg(feature = "std")]
static SCOPED_COUNT: AtomicUsize = AtomicUsize::new(0);

State 两个字段:default 是这个线程的线程默认(None 表示没有,用全局的),can_enter 是下文的防递归开关。SCOPED_COUNT 是进程级的计数:所有线程上「还活着的 DefaultGuard」一共有几个。

set_default 克隆传入的 Dispatch,交给 State::set_default:

    fn set_default(new_dispatch: Dispatch) -> DefaultGuard {
        let prior = CURRENT_STATE
            .try_with(|state| {
                state.can_enter.set(true);
                state.default.replace(Some(new_dispatch))
            })
            .ok()
            .flatten();
        EXISTS.store(true, Ordering::Release);
        SCOPED_COUNT.fetch_add(1, Ordering::Release);
        DefaultGuard(prior)
    }

新值放进线程局部,旧值装进守卫 DefaultGuard(Option<Dispatch>) 带走。守卫 drop 时(第 889 行)把旧值换回去:

impl Drop for DefaultGuard {
    #[inline]
    fn drop(&mut self) {
        // Replace the dispatcher and then drop the old one outside
        // of the thread-local context. Dropping the dispatch may
        // lead to the drop of a subscriber which, in the process,
        // could then also attempt to access the same thread local
        // state -- causing a clash.
        let prev = CURRENT_STATE.try_with(|state| state.default.replace(self.0.take()));
        SCOPED_COUNT.fetch_sub(1, Ordering::Release);
        drop(prev)
    }
}
  • 守卫里存的是「设之前是谁」,不是「我设的是谁」。drop 时不检查当前值是不是自己设的,直接覆盖。按创建的相反顺序 drop 就是一个栈;顺序乱了会怎样,见本节末尾的动脑筋。
  • 被换下来的 Dispatch 先拿出 try_with 的闭包,再 drop(prev)。如果这是最后一份引用,subscriber 的析构会在 RefCell 借用结束之后跑,析构里再打日志也不会撞上 already borrowed。
  • with_default 就是 let _guard = set_default(dispatcher); f()。注释解释了为什么用守卫而不是调用完 f 再手动恢复:f panic 时守卫照样会在栈展开中被 drop,默认值照样恢复。

只对当前线程有效

use std::thread;
use tracing::info;

fn main() {
  let _guard = tracing::subscriber::set_default(Named("A"));
  info!("主线程,A 已设为线程默认");

  thread::Builder::new()
    .name("worker".into())
    .spawn(|| {
      println!("worker 开始");
      info!("worker,什么都没设");
      tracing::subscriber::with_default(Named("B"), || {
        info!("worker,with_default(B) 里面");
      });
      info!("worker,with_default 返回之后");
      println!("worker 结束");
    })
    .unwrap()
    .join()
    .unwrap();

  info!("主线程,join 之后");
}

连跑 3 次输出相同:

  [A] 线程 main:主线程,A 已设为线程默认
worker 开始
  [B] 线程 worker:worker,with_default(B) 里面
  (B 被 drop)
worker 结束
  [A] 线程 main:主线程,join 之后
  (A 被 drop)

worker 线程的 CURRENT_STATE 是新的一份,default 为 None,退回全局默认;全局默认没设,就是 NONE,两条「worker」日志都没人收到。主线程的 A 在 _guard 离开 main 时才 drop。tokio 多线程运行时的任务会在不同的工作线程上被 poll(见 多线程调度器),在一个线程上 set_default,别的工作线程看不到;要把 dispatcher 带进 spawn 出去的任务,见 Instrument 与异步 里的 WithDispatch。

let _ 和 let _guard

use tracing::info;
use tracing::subscriber::set_default;

fn main() {
  println!("1. let _ = set_default(..)");
  let _ = set_default(Named("A"));
  info!("一");

  println!("2. let _guard = set_default(..)");
  let _guard = set_default(Named("B"));
  info!("二");
  drop(_guard);

  println!("3. 嵌套,后建的先 drop");
  let g1 = set_default(Named("C"));
  let g2 = set_default(Named("D"));
  info!("三:两个守卫都在");
  drop(g2);
  info!("三:drop g2 之后");
  drop(g1);
  info!("三:drop g1 之后");
}

连跑 3 次输出相同:

1. let _ = set_default(..)
  (A 被 drop)
2. let _guard = set_default(..)
  [B] 线程 main:二
  (B 被 drop)
3. 嵌套,后建的先 drop
  [D] 线程 main:三:两个守卫都在
  (D 被 drop)
  [C] 线程 main:三:drop g2 之后
  (C 被 drop)

let _ = expr 不绑定任何变量,守卫在这条语句结束时就 drop 了:A 刚装上就被换回 None,而且这是 A 的最后一份引用,它当场析构,info!("一") 没人收。let _guard 是一个普通变量,活到作用域结束(这里是显式 drop)。

set_default 带着 #[must_use],直接写成一条语句 tracing::subscriber::set_default(Named("A")); 时 rustc 1.99.0 会警告:

warning: unused return value of `tracing::subscriber::set_default` that must be used
 --> src/bin/must_use.rs:4:3
  |
4 |   tracing::subscriber::set_default(Named("A"));
  |   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  |
  = note: Dropping the guard unregisters the subscriber.
  = note: `#[warn(unused_must_use)]` (part of `#[warn(unused)]`) on by default
help: use `let _ = ...` to ignore the resulting value
  |
4 |   let _ = tracing::subscriber::set_default(Named("A"));
  |   +++++++

note 里说的是对的,help 给的改法恰好就是第 1 种写法:警告消失了,subscriber 照样没装上。

❗IMPORTANT
动脑筋:守卫按创建顺序 drop,最后一条日志有人收吗?

还是上面的 Named,M2 Max、rustc 1.99.0、--release:

use tracing::info;
use tracing::subscriber::set_default;

fn main() {
  let g1 = set_default(Named("E"));
  let g2 = set_default(Named("F"));
  drop(g1); // 先 drop 先建的那个
  info!("drop g1 之后");
  drop(g2);
  info!("drop g2 之后");
  println!("main 结束");
}

g1 带走的旧值是 None,g2 带走的旧值是 E。问:程序一共打印几行,「drop g2 之后」这条有没有被 E 收到?

get_default:快路径与慢路径

get_default 是两条主线问「交给谁」时调用的函数:

pub fn get_default<T, F>(mut f: F) -> T
where
    F: FnMut(&Dispatch) -> T,
{
    if SCOPED_COUNT.load(Ordering::Acquire) == 0 {
        // fast path if no scoped dispatcher has been set; just use the global
        // default.
        return f(get_global());
    }

    CURRENT_STATE
        .try_with(|state| {
            if let Some(entered) = state.enter() {
                return f(&entered.current());
            }

            f(&NONE)
        })
        .unwrap_or_else(|_| f(&NONE))
}
  • 快路径:整个进程里没有活着的 DefaultGuard 时,一次原子读加 get_global 里的一次原子读,不碰线程局部。只用 fmt().init() 之类全局默认的程序永远走这里。
  • 慢路径:只要任何一个线程持有守卫,所有线程都走慢路径,因为 SCOPED_COUNT 是进程级的。慢路径进线程局部,经 can_enter 检查后用 Entered::current 取值:本线程的 default 是 Some 就用它,None 就退回 get_global()。
  • 线程局部已销毁:线程退出、析构 TLS 时再打日志,try_with 返回 Err,用 NONE,不 panic。

返回 &Dispatch 给闭包、而不是返回一个克隆,是为了不在每条事件上做一次 Arc 加减。需要拥有一份的地方(Span::new 存进 span、Dispatch::default())在闭包里自己 clone。

📝NOTE
冷知识:线程局部曾经缓存全局默认,结果缓存住了「没有」

tracing-core 0.1.31 之前,get_default 先查线程局部;线程局部没有时去读全局默认,并把读到的结果缓存进线程局部。PR #2593 描述了问题:如果某个线程在全局默认设好之前就调用过 get_default,缓存进去的是 none,「the thread will now behave as though its default dispatcher is None until the scoped default is overridden, even if a global default is then set later」。修法是把 0.2 分支上 #1017 的做法搬回 0.1:用 SCOPED_COUNT 判断要不要碰线程局部,把 Dispatch 改成 Kind::Global(&'static ..) / Kind::Scoped(Arc) 二选一,NONE 变成静态单例,然后彻底去掉缓存。PR 里的基准显示全局默认下 Dispatch::get_ref 快了约 52%,线程默认下 get_clone 慢了约 53%,作者认为「a global default dispatcher is the common case for most users」,这个交换值得。随 tracing-core 0.1.31 发布。

can_enter:subscriber 在自己里面打日志

State::enter 把 can_enter 从 true 换成 false,返回的 Entered 守卫 drop 时再改回 true:

    fn enter(&self) -> Option<Entered<'_>> {
        if self.can_enter.replace(false) {
            Some(Entered(self))
        } else {
            None
        }
    }

get_default 调用 f 的整个过程中 can_enter 都是 false。Event::dispatch 的 f 里调的是 current.event(&event),如果 subscriber 的 event 里又打了一条日志,这条日志的 get_default 会看到 can_enter == false,拿到 NONE,被 NoSubscriber 丢掉。get_default 的文档也写了:嵌套调用时闭包拿到的是 Dispatch::none。

注意这个开关只在慢路径上。快路径直接 f(get_global()),没有任何检查。下面的 subscriber 在 event 里再打一条日志,用线程局部的深度计数在第 3 层停下:

use std::cell::Cell;
use std::fmt;
use tracing::field::Field;
use tracing::span::{Attributes, Id, Record};
use tracing::{Event, Metadata, Subscriber, info};

thread_local! {
  static DEPTH: Cell<usize> = const { Cell::new(0) };
}

/// 在自己的 event 里再打一条日志;深度到 3 就停,免得真的栈溢出。
struct Chatty;

impl Subscriber for Chatty {
  fn enabled(&self, _: &Metadata<'_>) -> bool {
    true
  }
  fn new_span(&self, _: &Attributes<'_>) -> Id {
    Id::from_u64(1)
  }
  fn record(&self, _: &Id, _: &Record<'_>) {}
  fn record_follows_from(&self, _: &Id, _: &Id) {}
  fn event(&self, event: &Event<'_>) {
    let mut msg = String::new();
    event.record(&mut |f: &Field, v: &dyn fmt::Debug| {
      if f.name() == "message" {
        msg = format!("{v:?}");
      }
    });
    let depth = DEPTH.with(|d| d.get());
    println!("  event 深度 {depth}:{msg}");
    if depth < 3 {
      DEPTH.with(|d| d.set(depth + 1));
      info!("subscriber 自己打的日志");
      DEPTH.with(|d| d.set(depth));
    }
  }
  fn enter(&self, _: &Id) {}
  fn exit(&self, _: &Id) {}
}

fn main() {
  println!("线程默认(set_default):");
  {
    let _guard = tracing::subscriber::set_default(Chatty);
    info!("用户的日志");
  }
  println!("全局默认(set_global_default):");
  tracing::subscriber::set_global_default(Chatty).unwrap();
  info!("用户的日志");
}

连跑 3 次输出相同:

线程默认(set_default):
  event 深度 0:用户的日志
全局默认(set_global_default):
  event 深度 0:用户的日志
  event 深度 1:subscriber 自己打的日志
  event 深度 2:subscriber 自己打的日志
  event 深度 3:subscriber 自己打的日志
  • 线程默认:SCOPED_COUNT 为 1,走慢路径。内层 info! 的调用点 Interest 是 always,跳过了第四道门,直接 Event::dispatch;get_default 看到 can_enter == false,交给 NONE。内层日志消失,没有报错。
  • 全局默认:_guard 已 drop,SCOPED_COUNT 回到 0,走快路径,内层日志又交给 Chatty::event,一层套一层。把 depth < 3 改成不设上限,进程在第 4 万多层时以 thread 'main' (…) has overflowed its stack 和 fatal runtime error: stack overflow, aborting 结束(线程号每次不同,已删)。

所以「subscriber 里打日志会被吞掉」只在线程默认下成立;写全局 subscriber 时,event 里的代码(包括它调用的库)不能无条件地再打 tracing 日志。

没有 subscriber 时

什么都不装,三道门都会挡住事件:

use tracing::info;
use tracing::level_filters::LevelFilter;
use tracing_core::subscriber::NoSubscriber;

fn side_effect() -> u32 {
  println!("  字段表达式被求值了");
  42
}

fn main() {
  println!("LevelFilter::current() = {}", LevelFilter::current());
  info!(x = side_effect(), "没有 subscriber");
  let is_none = tracing::dispatcher::get_default(|d| d.is::<NoSubscriber>());
  println!("get_default 给的是 NoSubscriber:{is_none}");
}

依赖加上 tracing-core = "=0.1.36"。连跑 3 次输出相同:

LevelFilter::current() = off
get_default 给的是 NoSubscriber:true
  • 全局的最大级别 MAX_LEVEL 初值是 LevelFilter::OFF,只在重算调用点缓存时被改写(Dispatch::new 或 rebuild_interest_cache 触发,见 级别过滤的几道门)。没人新建过 Dispatch,第二道门 level_enabled! 就返回 false,调用点不注册,字段表达式不求值(side_effect 没打印)。这是没开 log feature 时的情形;开了的话被挡住的事件还会交给 __tracing_log,见 和 log 互通。
  • 如果绕过前几道门直接调用,拿到的是 NONE。NoSubscriber 的 register_callsite 返回 Interest::never(),enabled 返回 false,new_span 返回固定的 Id::from_u64(0xDEAD),event、record、enter、exit 等是空函数。

WeakDispatch

WeakDispatch 是 Dispatch 的弱引用版,由 Dispatch::downgrade 得到,upgrade 返回 Option<Dispatch>:

impl Kind<Weak<dyn Subscriber + Send + Sync>> {
    fn upgrade(&self) -> Option<Kind<Arc<dyn Subscriber + Send + Sync>>> {
        match self {
            Kind::Global(s) => Some(Kind::Global(*s)),
            Kind::Scoped(ref s) => Some(Kind::Scoped(s.upgrade()?)),
        }
    }
}

全局默认的那份永远升级成功(它是 &'static);线程默认的那份在所有 Dispatch 克隆都 drop 后返回 None。

它的用处写在 Subscriber::on_register_dispatch 的文档里:subscriber 想拿着「装着自己的那个 Dispatch」(比如交给一个后台线程,让它以后能往同一个 subscriber 里发事件),存强引用就成了环,Dispatch 永远不会被释放;存 WeakDispatch 就没有这个问题。WeakDispatch 正是为此在 PR #2293 里加进来的,和 on_register_dispatch 一起随 tracing-core 0.1.30 发布。callsite 模块内部的 dispatcher 列表也存弱引用(私有的 Registrar),所以一个线程默认被丢掉后,它不会再参与 Interest 的计算。

动脑筋答案

M2 Max、rustc 1.99.0、--release,连跑 3 次输出相同:

  (F 被 drop)
main 结束
  (E 被 drop)

一共 3 行,两条日志都没人收。

  • drop(g1):把线程局部换成 g1 带走的 None,换下来的 F 没有别的引用了,当场析构(第 1 行)。SCOPED_COUNT 从 2 变 1,get_default 走慢路径,本线程 default 是 None,退回全局,全局没设,「drop g1 之后」被 NONE 丢掉。
  • drop(g2):把线程局部换成 g2 带走的 E。E 又成了本线程的线程默认,但这时 SCOPED_COUNT 已经是 0,get_default 走快路径,根本不看线程局部,「drop g2 之后」还是交给了 NONE。
  • 第 3 行:E 一直躺在主线程的 CURRENT_STATE 里,直到线程局部被析构才 drop,所以出现在「main 结束」之后。

这个 E 并没有彻底失效。在同样两次 drop 之后,让另一个线程持有一个守卫(SCOPED_COUNT 变成 1),主线程再打一条日志,再让那个线程退出、最后再打一条:

  (F 被 drop)
  [E] 线程 main:别的线程持有守卫时
  (G 被 drop)
  (E 被 drop)

(这段程序是 guards_ghost.rs:用两个 mpsc 通道让 worker 在 set_default(Named("G")) 之后停住,主线程在这期间 info!。连跑 3 次相同。)别的线程一持有守卫,主线程就走慢路径,读到了本该已经恢复成「没有」的 E。守卫按相反顺序 drop 时,每次换回去的都是正确的值,不会出现这种情况。

小结

  • Dispatch 内部是 Kind::Global(&'static dyn Subscriber) 或 Kind::Scoped(Arc<dyn Subscriber>);set_global_default 用 Arc::into_raw 把 Arc 有意泄漏成 &'static,此后克隆全局默认不碰引用计数。
  • GLOBAL_INIT 三态:UNINITIALIZED → INITIALIZING → INITIALIZED,compare_exchange 只让一个调用成功,其余立即得到 SetGlobalDefaultError(「a global default trace dispatcher has already been set」);初始化完成前读到的是 NONE。
  • set_default 把新值放进线程局部 CURRENT_STATE,旧值放进 DefaultGuard,守卫 drop 时换回旧值。只对当前线程有效;let _ = 让守卫当场 drop;守卫要按相反顺序 drop。
  • get_default 在进程级的 SCOPED_COUNT 为 0 时只读全局,不碰线程局部;任何线程持有守卫,所有线程都走慢路径。
  • can_enter 让线程默认下 subscriber 自己打的日志交给 NONE;全局默认走快路径,没有这层保护,会一直递归到栈溢出。
  • 没装 subscriber 时 LevelFilter::current() 是 off,事件在第二道门就停了;NoSubscriber 什么都不收。WeakDispatch 让 subscriber 存自己的 Dispatch 而不成环。

💬 关联讨论

发起讨论
加载中...