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」不额外占空间。
Id 原来是普通的 u64tracing-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 构造 | 宏写法 |
|---|---|---|---|
Current | Attributes::new | Event::new | 不写 parent: |
Root | Attributes::new_root | Event::new_child_of(None, ..) | parent: None |
Explicit(id) | Attributes::child_of | Event::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」得到的。
问: 宏既然在调用线程上,为什么不在构造 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(见 字段)。
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 里 |
None | Current::none()(pub) | 跟踪了,当前不在任何 span 里 |
Unknown | Current::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, ..)。两者做三件事:
- 在栈上构造
Event,只是三个字段的赋值; dispatcher::get_default找到当前线程的 dispatcher(线程局部的默认值,或者全局的),见 Dispatch:全局与线程局部;- 调
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。