Rust in Everything
基于 tracing-core 0.1.36

span 与 Event 的数据

主线位置:两条主线都经过这里。span 主线上,info_span! 过了几道门以后把元数据、字段和父 span 标记包成 span::Attributes 交给 new_span,拿回一个 span::Id;Span::record 补字段时包成 span::Record;Span::current() 向 subscriber 要一个 span::Current。事件主线上,info! 构造一个 Event,Event::dispatch 把它交给当前 dispatcher 的 event。

flowchart TB
  m1["info_span!(...)"] --> cur["Parent::Current"]
  m2["parent: None"] --> root["Parent::Root"]
  m3["parent: 某个 span"] --> into{"span 有 Id?"}
  into -->|有| expl["Parent::Explicit(id)"]
  into -->|没有| root
  cur --> attrs["Attributes / Event"]
  root --> attrs
  expl --> attrs
  attrs --> sub["subscriber 读取"]
  sub -->|is_contextual| stack["查自己的当前 span"]
  sub -->|is_root| noparent["没有父"]
  sub -->|"parent()"| given["用给定的 Id"]

这一页讲 span.rs、event.rs 和只有 11 行的 parent.rs。这些类型都很薄:元数据是 &'static,字段值借用宏在栈上摆好的 ValueSet,自己只多存一个父 span 标记。subscriber 收到它们以后在 new_span、record、event 里做什么,见 Subscriber trait;用户手里的 Span、enter、Entered 见 Span 与 Entered。

span::Id:subscriber 发的号

Id 是一个 NonZeroU64 的新类型:

#[derive(Clone, Debug, PartialEq, Eq, Hash)]
pub struct Id(NonZeroU64);

它由 subscriber 的 new_span 返回,tracing-core 和 tracing 都不解释它的含义:只是拿它去调 enter、exit、record、clone_span、try_close。Registry 用 sharded-slab 的 key 加一当 Id(key 里打包了槽地址、线程号和代数),见 Registry。

构造它有两条路。Id::from_u64 遇到 0 会 panic,消息是 span IDs must be > 0;from_non_zero_u64 是 const fn,类型上就排除了 0。Id 没有实现 Copy(源码注释:「we don't want to impl Copy for Id」),所以取值的方法叫 into_u64(&self),还要为这个名字关掉 clippy 的 wrong_self_convention。

不能为 0 的好处是 niche 优化:Option<Id> 和 Id 一样是 8 字节(下面实验里实测),「没有父 span」不额外占空间。

📝NOTE
冷知识:Id 原来是普通的 u64

tracing-core 0.1.0 发布之前,#106 把 Id 的内部表示从 u64 换成了 NonZeroU64。PR 说明:最低 Rust 版本升到 1.34 之后,可以处理一些「long-standing TODOs that were previously not possible to address because they required features unavailable on Rust 1.26」,其中一项是「changes the internal representation of tracing_core::span::Id to benefit from non-zero optimization」。首个包含它的版本是 tracing-core 0.1.0。

后来 #770 又加了 from_non_zero_u64 / into_non_zero_u64,理由是「Consumers of the crate should be able to handle the 0 case separately and avoiding panicking within Id::from_u64」,首次发布在 tracing-core 0.1.11。

Attributes 与 Record

Attributes 是 new_span 的参数,Record 是 record 的参数:

pub struct Attributes<'a> {
    metadata: &'static Metadata<'static>,
    values: &'a field::ValueSet<'a>,
    parent: Parent,
}

pub struct Record<'a> {
    values: &'a field::ValueSet<'a>,
}

Record 不带元数据和父 span:调用 record 时 subscriber 已经有这个 span 的 Id,元数据在 new_span 时就存下了。两者的读取方法几乎一样,都转给 ValueSet:record(visitor)、contains(field)、is_empty();Record 还有 len()。

Attributes 多两个:metadata(),和 fields()。注意 fields() 返回的是整张 FieldSet,包含所有声明过的字段,不只是这次有值的那些;文档说得明白:「includes all the fields declared by this span ... Other fields with values not present in this Attributes' value set may record values later」。field::Empty 占位的字段就在这里出现、在 record(visitor) 里不出现。

三种父 span

父 span 的三种情况是 tracing-core 内部的 Parent:

#[derive(Debug)]
pub(crate) enum Parent {
    /// The new span will be a root span.
    Root,
    /// The new span will be rooted in the current span.
    Current,
    /// The new span has an explicitly-specified parent.
    Explicit(Id),
}

它是 pub(crate),外面看不到这个枚举,只能通过构造函数选、通过三个方法问。Attributes 和 Event 共用它:

情况Attributes 构造Event 构造宏写法
CurrentAttributes::newEvent::new不写 parent:
RootAttributes::new_rootEvent::new_child_of(None, ..)parent: None
Explicit(id)Attributes::child_ofEvent::new_child_of(Some(id), ..)parent: &span、parent: span.id()

Event 的 new_child_of 收 impl Into<Option<Id>>,None 直接变成 Root:

let parent = match parent.into() {
    Some(p) => Parent::Explicit(p),
    None => Parent::Root,
};

Attributes::child_of 只收 Id,Option 的分支在 tracing 这边:span! 带 parent: 的分支调 Span::child_of,它的 child_of_with 做同样的分支:

let new_span = match parent.into() {
    Some(parent) => Attributes::child_of(parent, meta, values),
    None => Attributes::new_root(meta, values),
};

不带 parent: 的分支调 Span::new,即 Attributes::new,父是 Current。

parent: &span 能编译,是因为 tracing 实现了 From<&Span> for Option<Id>:

impl<'a> From<&'a Span> for Option<Id> {
    fn from(span: &'a Span) -> Self {
        span.inner.as_ref().map(Inner::id)
    }
}

被过滤掉的 span 没有 inner,转出来是 None。于是 parent: &被关掉的 span 和 parent: None 走同一条路:新 span 或事件成了根,而不是退回到当前 span。本页的「动脑筋」就问这个。

subscriber 怎么读父 span

三个方法,Attributes 和 Event 上各一套,实现完全一样(Attributes::is_root 起):

方法为真 / 有值的条件
is_root()Parent::Root
is_contextual()Parent::Current
parent()Parent::Explicit(id) 时返回 Some(&id),另外两种返回 None

parent() 返回 None 不说明「没有父」,可能是根,也可能是「看上下文」。subscriber 要先问 is_root / is_contextual。

Current 只是一个标记,里面没有 Id:tracing-core 不知道「当前 span」是谁,因为进入、退出 span 的记录在 subscriber 手里。解析发生在 subscriber 内部。Registry::new_span 开头就是三选一:

fn new_span(&self, attrs: &span::Attributes<'_>) -> span::Id {
    let parent = if attrs.is_root() {
        None
    } else if attrs.is_contextual() {
        self.current_span().id().map(|id| self.clone_span(id))
    } else {
        attrs.parent().map(|id| self.clone_span(id))
    };
    // ...

事件这边是 tracing-subscriber 的 Context::event_span,fmt 用它找事件所在的 span 链:

if event.is_root() {
    None
} else if event.is_contextual() {
    self.lookup_current()
} else {
    // TODO(eliza): this should handle parent IDs
    event.parent().and_then(|id| self.span(id))
}

两处都是「问清是哪种,再决定去哪里找」。解析时机也就确定了:contextual 的父是在 new_span / event 被调用的那一刻、在调用线程上,由 subscriber 查它自己的「当前 span」得到的。

📝NOTE
没有蠢问题

问: 宏既然在调用线程上,为什么不在构造 Attributes 时就把当前 span 的 Id 查好放进去,非要留一个 Current 让 subscriber 自己查?

答: 宏手里没有答案。「当前 span」是 subscriber 记录 enter / exit 得到的状态(Registry 是每个线程一个 span 栈),tracing-core 只能通过 Subscriber::current_span 去问,而这个方法的默认实现返回「不知道」(见下一节),上面的打印 subscriber 就没有实现它。new_span 本来就是交给 subscriber 的,留一个 Current 标记,让唯一知道答案的一方自己查,tracing-core 就不必假定每个 subscriber 都跟踪当前 span。

下面这个 subscriber 自己分配 Id、自己维护一个线程局部的 span 栈,在 new_span 和 event 里打印父 span 的种类;遇到 contextual,就顺手查自己的栈。它的 enabled 关掉了 DEBUG 及更详细的级别。

tracing = "=0.1.44"
use std::{
  cell::RefCell,
  sync::atomic::{AtomicU64, Ordering},
};

use tracing::{span, Event, Level, Metadata, Subscriber};

// 最小的打印 subscriber:自己分配 Id、自己维护「当前 span」栈
struct Printer {
  next_id: AtomicU64,
}

thread_local! {
  static STACK: RefCell<Vec<u64>> = const { RefCell::new(Vec::new()) };
}

fn current() -> Option<u64> {
  STACK.with(|s| s.borrow().last().copied())
}

fn kind(is_root: bool, is_contextual: bool, parent: Option<&span::Id>) -> String {
  match (is_root, is_contextual, parent) {
    (true, _, _) => "root".to_string(),
    (_, true, _) => format!("contextual -> current = {:?}", current()),
    (_, _, Some(p)) => format!("explicit({})", p.into_u64()),
    _ => unreachable!("Parent 只有三种"),
  }
}

impl Subscriber for Printer {
  fn enabled(&self, meta: &Metadata<'_>) -> bool {
    // DEBUG 及更详细的 span/事件一律关掉
    *meta.level() <= Level::INFO
  }
  fn new_span(&self, attrs: &span::Attributes<'_>) -> span::Id {
    let id = self.next_id.fetch_add(1, Ordering::Relaxed);
    println!(
      "new_span {:<8} id={id}  {}",
      attrs.metadata().name(),
      kind(attrs.is_root(), attrs.is_contextual(), attrs.parent()),
    );
    span::Id::from_u64(id)
  }
  fn record(&self, _: &span::Id, _: &span::Record<'_>) {}
  fn record_follows_from(&self, _: &span::Id, _: &span::Id) {}
  fn event(&self, event: &Event<'_>) {
    let mut msg = String::new();
    event.record(&mut |_: &tracing::field::Field, v: &dyn std::fmt::Debug| {
      msg = format!("{v:?}");
    });
    println!(
      "event    {msg:<8}       {}",
      kind(event.is_root(), event.is_contextual(), event.parent()),
    );
  }
  fn enter(&self, id: &span::Id) {
    STACK.with(|s| s.borrow_mut().push(id.into_u64()));
  }
  fn exit(&self, _: &span::Id) {
    STACK.with(|s| s.borrow_mut().pop());
  }
}

fn main() {
  let sub = Printer { next_id: AtomicU64::new(1) };
  tracing::subscriber::with_default(sub, || {
    let outer = tracing::info_span!("outer");
    tracing::info!("e0");
    let _g = outer.enter();
    let ctx = tracing::info_span!("ctx");
    let root = tracing::info_span!(parent: None, "root");
    let off = tracing::debug_span!("off");
    let child = tracing::info_span!(parent: &root, "child");
    let orphan = tracing::info_span!(parent: &off, "orphan");
    tracing::info!("e1");
    tracing::info!(parent: None, "e2");
    tracing::info!(parent: &root, "e3");
    tracing::info!(parent: &off, "e4");
    drop((ctx, child, orphan));
  });
  println!(
    "size_of: Id={} Option<Id>={}",
    std::mem::size_of::<span::Id>(),
    std::mem::size_of::<Option<span::Id>>(),
  );
}

event 里传了一个闭包当 visitor:tracing-core 给 FnMut(&Field, &dyn Debug) 实现了 Visit(见 字段)。

❗IMPORTANT
动脑筋:orphan 和 e4 的父 span 是谁?

上面的程序里,off 是 debug_span!,被 enabled 关掉了。orphan 写的是 parent: &off,e4 写的是 parent: &off,两者都在 outer 已进入的时候创建。它们打印出来是 explicit(...)、contextual -> current = Some(1),还是 root?

把同一段 main 换成 tracing-subscriber 的 Registry,由它来解析父 span,再用一个只打印结果的 layer 看它的结论:

tracing = "=0.1.44"
tracing-subscriber = { version = "=0.3.23", default-features = false, features = ["fmt"] }
use tracing::{span, Event, Subscriber};
use tracing_subscriber::{
  filter::LevelFilter, layer::Context, prelude::*, registry::LookupSpan, Layer,
};

// 让 Registry 去解析父 span,这个 layer 只负责把结果打印出来
struct ShowParent;

impl<S> Layer<S> for ShowParent
where
  S: Subscriber + for<'a> LookupSpan<'a>,
{
  fn on_new_span(&self, _: &span::Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) {
    let span = ctx.span(id).expect("刚创建的 span 一定在 Registry 里");
    let parent = span.parent().map(|p| p.name());
    println!("new_span {:<8} parent = {parent:?}", span.name());
  }
  fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
    let mut msg = String::new();
    event.record(&mut |_: &tracing::field::Field, v: &dyn std::fmt::Debug| {
      msg = format!("{v:?}");
    });
    let parent = ctx.event_span(event).map(|s| s.name());
    println!("event    {msg:<8} parent = {parent:?}");
  }
}

fn main() {
  let sub = tracing_subscriber::registry().with(LevelFilter::INFO).with(ShowParent);
  tracing::subscriber::with_default(sub, || {
    // ... 与上一个程序相同的 span 和事件
  });
}

两个程序的输出放在本页末尾的「动脑筋答案」里。

span::Current:subscriber 眼里的当前 span

Current 是 Subscriber::current_span 的返回值,有三种状态:

enum CurrentInner {
    Current {
        id: Id,
        metadata: &'static Metadata<'static>,
    },
    None,
    Unknown,
}
状态构造含义
Current { id, metadata }Current::new(id, meta)(pub)当前在这个 span 里
NoneCurrent::none()(pub)跟踪了,当前不在任何 span 里
UnknownCurrent::unknown()(pub(crate))这个 subscriber 不跟踪当前 span

Unknown 的构造函数不公开,subscriber 只能通过「不覆盖 current_span」得到它:默认实现就是 span::Current::unknown()。is_known 用来区分后两种,id()、metadata()、into_inner() 对后两种都返回 None。

Current 带着 metadata,因为使用者往往是只拿到 dispatcher 的代码:tracing 的 Span::current 用 into_inner() 拿到 (id, meta),clone_span 增加引用计数后拼成一个 Span 句柄;拿不到就返回 Span::none()。Registry 的 current_span 读本线程的 span 栈,栈空时返回 Current::none。上面那个打印 subscriber 没有覆盖 current_span,在它下面 Span::current() 总是 Span::none():在那个程序 outer 进入期间加一行 println!("{}", tracing::Span::current().is_none()),打印 true,虽然它自己的栈里明明有 span。

Event 与 Event::dispatch

Event 和 Attributes 同构:

pub struct Event<'a> {
    fields: &'a field::ValueSet<'a>,
    metadata: &'static Metadata<'static>,
    parent: Parent,
}

它没有 Id:事件是一个时间点,subscriber 收到 event 以后不会再被问到它。

宏不直接构造 Event,而是调两个「构造并分发」的函数。Event::dispatch 用于不带 parent: 的事件:

pub fn dispatch(metadata: &'static Metadata<'static>, fields: &'a field::ValueSet<'_>) {
    let event = Event::new(metadata, fields);
    crate::dispatcher::get_default(|current| {
        current.event(&event);
    });
}

Event::child_of 用于带 parent: 的事件,只是把 Event::new 换成 Event::new_child_of(parent, ..)。两者做三件事:

  1. 在栈上构造 Event,只是三个字段的赋值;
  2. dispatcher::get_default 找到当前线程的 dispatcher(线程局部的默认值,或者全局的),见 Dispatch:全局与线程局部;
  3. 调 Dispatch::event,它在真正调用 Subscriber::event 之前还有一道检查:
pub fn event(&self, event: &Event<'_>) {
    let subscriber = self.subscriber();
    if subscriber.event_enabled(event) {
        subscriber.event(event);
    }
}

event_enabled 是第四道门之后的最后一次过滤,和 enabled 不同,它能看到字段值;默认返回 true,见 Subscriber trait。

在 event! 里,这一步被包在一个立即调用的闭包里:(|value_set: ValueSet| { ... Event::dispatch(meta, &value_set); })(valueset_all!(...)),ValueSet 只在门都通过之后才构造。宏怎么展开见 宏展开。

只构造不分发的 Event::new 和 new_child_of 是 #281 加的(tracing-core 0.1.5),动机是 layer 汇总事件后再转发:「there is a compelling use-case for constructing events without immediately dispatching them to the default subscriber」。

Event 的读取方法:record(visitor) 转给 ValueSet;fields() 返回整张 FieldSet 的迭代器(同样包含没有值的字段);metadata();以及和 Attributes 一样的 is_root、is_contextual、parent。

动脑筋答案

M2 Max、rustc 1.99.0、--release,两个程序各跑 3 次,输出相同。打印 subscriber:

new_span outer    id=1  contextual -> current = None
event    e0             contextual -> current = None
new_span ctx      id=2  contextual -> current = Some(1)
new_span root     id=3  root
new_span child    id=4  explicit(3)
new_span orphan   id=5  root
event    e1             contextual -> current = Some(1)
event    e2             root
event    e3             explicit(3)
event    e4             root
size_of: Id=8 Option<Id>=8

Registry 加打印 layer:

new_span outer    parent = None
event    e0       parent = None
new_span ctx      parent = Some("outer")
new_span root     parent = None
new_span child    parent = Some("root")
new_span orphan   parent = None
event    e1       parent = Some("outer")
event    e2       parent = None
event    e3       parent = Some("root")
event    e4       parent = None

orphan 和 e4 都是 root。

  • off 被 enabled 关掉,没有 new_span 行,id 也没有被占用(child 是 4、orphan 是 5,中间没有空号)。它是一个没有 inner 的 Span,From<&Span> for Option<Id> 给出 None,Span::child_of 和 Event::new_child_of 都把 None 当成「明确要根」。虽然当时 outer 正处于进入状态,它们也不会挂到 outer 下面。
  • outer 和 e0 是 contextual,但当时栈是空的,所以没有父。Attributes 里只写着「看上下文」,结论由 subscriber 得出。
  • ctx 和 e1 同样是 contextual,这次栈顶是 outer(id 1);Registry 给出同样的结论。
  • root / e2 是 parent: None,child / e3 是 parent: &root,与是否在 outer 里无关。
  • Option<Id> 和 Id 都是 8 字节:NonZeroU64 的 niche 被 None 用掉了。

小结

  • Attributes、Record、Event 都是借用:&'static Metadata + &ValueSet,Attributes 和 Event 再加一个父 span 标记;Record 只有值。
  • 父 span 有三种:Explicit(Id)、Current、Root,枚举是 pub(crate) 的,subscriber 用 parent()、is_contextual()、is_root() 问;parent() 为 None 不等于没有父。
  • Current 不带 Id,由 subscriber 在 new_span / event 里查自己的当前 span 来解析(Registry::new_span、Context::event_span)。
  • parent: &span 经 Into<Option<Id>> 转换;被过滤掉的 span 转成 None,新 span 或事件变成根。
  • span::Id 是 NonZeroU64,由 subscriber 分配,Option<Id> 仍是 8 字节;span::Current 区分「在某个 span 里」「不在任何 span 里」「不跟踪」。
  • Event::dispatch / Event::child_of 在栈上构造 Event,经 get_default 找到 dispatcher,过 event_enabled 后调 Subscriber::event。

💬 关联讨论

发起讨论
加载中...