文件要 DEBUG、终端要 INFO,结果两边一样
主线位置:事件主线的第三、四道门。全局过滤器在
register_callsite说never、在enabled说false,整个栈到此为止,哪一层都轮不到on_event;每层过滤只在被包的那一层的on_event前起作用。
flowchart TB
ev["debug! 到达"] --> where{"过滤器怎么装的"}
where -->|".with(filter)"| g["全局:整个栈短路"]
g --> none["终端、文件都没有"]
where -->|"layer.with_filter"| p["每层:各查各的位"]
p --> fileok["文件层收到"]
p --> termno["终端层跳过"]
where -->|"两者都有"| both["全局先说 never"]
both --> none
想要的效果:终端只看 INFO,日志文件多记 DEBUG。写出来却是两边一模一样,要么文件里也没有 DEBUG,要么终端里也刷满 DEBUG。全局过滤和每层过滤的实现在 过滤:全局与每层 里拆过,这一页只讲怎么踩上、怎么改、怎么查。
复现
一个终端层(stdout)、一个文件层(真的写文件),三种装法,外加一种常见的「在 fmt() 上再加一层」:
tracing = "=0.1.44"
tracing-subscriber = { version = "=0.3.23", features = ["env-filter"] }
use std::fs::{self, File};
use tracing_subscriber::filter::LevelFilter;
use tracing_subscriber::prelude::*;
use tracing_subscriber::{EnvFilter, fmt};
fn emit() {
tracing::info!("server started");
tracing::debug!("cache warmed");
}
fn file(path: &str) -> File {
File::create(path).unwrap()
}
fn show(path: &str) {
print!("-- {path}:\n{}", fs::read_to_string(path).unwrap());
}
fn main() {
let case = std::env::args().nth(1).unwrap();
let path = format!("{case}.log");
println!("== {case}");
match case.as_str() {
// 过滤器用 .with 叠上去:全局
"global" => {
let sub = tracing_subscriber::registry()
.with(EnvFilter::new("info"))
.with(fmt::layer().with_ansi(false).without_time())
.with(fmt::layer().with_ansi(false).without_time().with_writer(file(&path)));
tracing::subscriber::with_default(sub, emit);
}
// 全局 INFO,文件层再加自己的 DEBUG
"global-plus-layer" => {
let sub = tracing_subscriber::registry()
.with(EnvFilter::new("info"))
.with(fmt::layer().with_ansi(false).without_time())
.with(
fmt::layer()
.with_ansi(false)
.without_time()
.with_writer(file(&path))
.with_filter(LevelFilter::DEBUG),
);
tracing::subscriber::with_default(sub, emit);
}
// 每层过滤
"per-layer" => {
let sub = tracing_subscriber::registry()
.with(fmt::layer().with_ansi(false).without_time().with_filter(EnvFilter::new("info")))
.with(
fmt::layer()
.with_ansi(false)
.without_time()
.with_writer(file(&path))
.with_filter(LevelFilter::DEBUG),
);
tracing::subscriber::with_default(sub, emit);
}
// 在 fmt() 造好的 subscriber 上再加一个带过滤的层
"fmt-plus-filtered" => {
let sub = tracing_subscriber::fmt()
.with_ansi(false)
.without_time()
.with_env_filter("info")
.finish()
.with(
fmt::layer()
.with_ansi(false)
.without_time()
.with_writer(file(&path))
.with_filter(LevelFilter::DEBUG),
);
tracing::subscriber::with_default(sub, emit);
}
_ => unreachable!(),
}
show(&path);
}
M2 Max、rustc 1.99.0、--release,四种各跑 3 次,除线程号外输出相同:
== global
INFO two_outputs: server started
-- global.log:
INFO two_outputs: server started
== global-plus-layer
INFO two_outputs: server started
-- global-plus-layer.log:
INFO two_outputs: server started
== per-layer
INFO two_outputs: server started
-- per-layer.log:
INFO two_outputs: server started
DEBUG two_outputs: cache warmed
== fmt-plus-filtered
thread 'main' (1605750) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-subscriber-0.3.23/src/registry/mod.rs:149:9:
tracing_subscriber::fmt::Subscriber<tracing_subscriber::fmt::format::DefaultFields, tracing_subscriber::fmt::format::Format<tracing_subscriber::fmt::format::Full, ()>, tracing_subscriber::filter::env::EnvFilter> does not currently support filters
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
global:文件里没有DEBUG。把"info"改成"debug",终端也会多出DEBUG。一个全局过滤器只有一个答案。global-plus-layer:文件层自己加了with_filter(LevelFilter::DEBUG),仍然没有DEBUG。这是最容易让人以为「每层过滤不生效」的写法。per-layer:两层各拿到自己要的。fmt-plus-filtered:根本跑不起来,panic 发生在组装 subscriber 的.with(..)里。
为什么
全局过滤器是一层。 EnvFilter、LevelFilter 都实现了 Layer,.with(filter) 把它叠进栈里。Layered::enabled 从外往里问,问到它说 false 就整体返回 false,宏不构造事件,所有层都看不到。它放在 .with 链的哪个位置都一样。fmt().with_env_filter(..) 和 fmt().with_max_level(..) 也是这一种:SubscriberBuilder::finish 把过滤器叠在最外层。
全局 INFO 加单层 DEBUG 是「与」。 debug! 的调用点注册时,文件层的 Filtered 记下「要」,但内层的全局 EnvFilter 回答 never,Layered 短路并清掉每层过滤记下的意见,调用点缓存成 never。每层过滤只能在全局放行的范围内再收窄。逐步推导和实测在 过滤:全局与每层 的「动脑筋答案」。
fmt() 的产物不能承载每层过滤。 Layer::with_filter 返回的 Filtered 被叠上去时要向内层领一个 FilterId,调的是 LookupSpan::register_filter。只有 Registry::register_filter 真正分配,Layered 往里转发;LookupSpan 的默认实现直接 panic:
fn register_filter(&mut self) -> FilterId {
panic!(
"{} does not currently support filters",
std::any::type_name::<Self>()
)
}
fmt::Subscriber 是包着 Layered 的新类型,它的 LookupSpan 实现 只转发了 span_data,没有转发 register_filter,于是落到默认实现。panic 消息里那一长串类型名就是 std::any::type_name::<Self>()。
问: 既然 fmt::Subscriber 里面就是一个 Registry,为什么不把 register_filter 也转发进去,让 fmt().finish().with(layer.with_filter(..)) 能用?
答: 转发了也得不到想要的结果。fmt() 的过滤器在 fmt::Subscriber 内部的最外层,是全局过滤;新加的层在它外面,它说 never 时整个栈照样短路,新层的 DEBUG 还是收不到,和 global-plus-layer 一样。想让各层级别不同,起点就该是 registry(),而不是已经带着全局过滤器的 fmt()。panic 至少让这个组合在启动时就暴露,而不是安静地丢日志。
修法
从 registry() 开始,每一个需要过滤的层都用 with_filter,栈里不留全局过滤器:
use tracing_subscriber::filter::LevelFilter;
use tracing_subscriber::prelude::*;
use tracing_subscriber::{EnvFilter, fmt};
let file_writer = std::fs::File::create("app.log").unwrap();
tracing_subscriber::registry()
.with(fmt::layer().with_filter(EnvFilter::from_default_env()))
.with(fmt::layer().with_ansi(false).with_writer(file_writer).with_filter(LevelFilter::DEBUG))
.init();
EnvFilter既能当全局过滤也能当每层过滤,RUST_LOG照样只管终端那一层。- 文件层什么级别都要时,可以只给终端加
with_filter,文件层不加。但不要为了「省一个」把文件的DEBUG写成全局的.with(LevelFilter::DEBUG):那等于给终端也放开了DEBUG,终端那层的with_filter还得照写。 - 已经有
fmt().with_env_filter(..)的代码,要加第二个出口,就把它拆成registry().with(fmt::layer().with_filter(..)),不要在fmt()的结果上接.with(..)。
只想按级别把同一行分到不同出口(比如 WARN 以上另抄一份),不需要第二个层,用 MakeWriterExt 的 with_max_level / or_else / and,见 fmt 的「组合子」一节。
怎么确认自己没踩
读初始化代码:
.with(后面直接跟EnvFilter、LevelFilter、Targets、filter_fn(..)的,都是全局过滤;fmt().with_env_filter/with_max_level也是。栈里只要有一个全局过滤器,所有层的上限就是它。启动时故意打一条比终端级别低的事件(比如
debug!("logging ready")),确认它出现在文件里、没出现在终端。只看LevelFilter::current()不够:global-plus-layer那种装法下,在with_default里打印它:let sub = tracing_subscriber::registry() .with(EnvFilter::new("info")) .with(fmt::layer().with_ansi(false).without_time()) .with(fmt::layer().with_ansi(false).without_time().with_filter(LevelFilter::DEBUG)); tracing::subscriber::with_default(sub, || { println!("LevelFilter::current() = {}", LevelFilter::current()); });LevelFilter::current() = debug(跑 3 次相同。)每层过滤的
DEBUG提示参与了取最大值,第二道门放行debug!,可文件里还是没有DEBUG,挡住它的是第三道门的Interest缓存。does not currently support filters的 panic 里,类型名开头是tracing_subscriber::fmt::Subscriber就是上面第四种;开头是别的类型,说明那个根 subscriber 不是Registry,同样要换成registry()起步。
小结
.with(filter)和fmt().with_env_filter(..)是全局过滤,说「不」时整个栈都看不到,放在链的哪里都一样。- 每层不同级别要用
layer.with_filter(filter),而且栈里不能再有比它更严的全局过滤:两者叠加是「与」,单层的DEBUG收不到被全局INFO挡掉的事件。 - 每层过滤要向根 subscriber 领
FilterId,只有Registry能发;在fmt().finish()上加with_filter的层,组装时 panic「does not currently support filters」。 - 检查办法是启动时打一条低级别事件看它落在哪,而不是看
LevelFilter::current()。