release 构建里 debug! 全部消失
主线位置:事件主线的第一道门
STATIC_MAX_LEVEL。它是编译期常量,挡住的事件连代码都不生成,后面几道门和 subscriber 的配置都碰不到它们。
flowchart TB dep["某个依赖开了 release_max_level_info"] --> unify["feature 合并"] unify --> one["整个程序只有一份 tracing"] one --> smax["release 下 STATIC_MAX_LEVEL = INFO"] smax --> gone["所有 debug! trace! 被删掉"] gone --> envf["RUST_LOG=debug 也没用"] tree["cargo tree -e features -i tracing"] -.->|找出是谁| dep
dev 构建里一切正常,换成 --release,所有 debug! 都不见了;subscriber 明明设成了 TRACE,RUST_LOG=debug 也没用。你的 Cargo.toml 里没写任何级别 feature。这种情况先查 STATIC_MAX_LEVEL。
现象
一个三个包的 workspace:app 依赖 mid,mid 依赖 quiet-dep,只有 quiet-dep 给 tracing 开了 release_max_level_info。
# quiet-dep/Cargo.toml
[dependencies]
tracing = { version = "=0.1.44", features = ["release_max_level_info"] }
# mid/Cargo.toml:不直接依赖 tracing
[dependencies]
quiet-dep = { path = "../quiet-dep" }
# app/Cargo.toml
[dependencies]
mid = { path = "../mid" }
tracing = "=0.1.44"
tracing-subscriber = { version = "=0.3.23", default-features = false, features = ["fmt", "std"] }
quiet-dep 的 work() 打一条 info!,mid::run() 调它。app 的 main:
use tracing::level_filters::STATIC_MAX_LEVEL;
use tracing::{Level, debug, info};
fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::TRACE)
.with_ansi(false)
.without_time()
.init();
let profile = if cfg!(debug_assertions) { "dev" } else { "release" };
info!(profile, %STATIC_MAX_LEVEL, "start");
debug!(user_id = 42, "cache miss");
mid::run();
}
M2 Max、rustc 1.99.0,cargo run -p app 和 cargo run -p app --release 各跑 3 次,输出相同。dev:
INFO app: start profile="dev" STATIC_MAX_LEVEL=trace
DEBUG app: cache miss user_id=42
INFO quiet_dep: quiet-dep working
release:
INFO app: start profile="release" STATIC_MAX_LEVEL=info
INFO quiet_dep: quiet-dep working
app 自己的 debug! 没了,而 app 从没写过 release_max_level_info。subscriber 设成了 TRACE,没有任何作用。
为什么是整个程序
两件事叠在一起:
- feature 在依赖图里合并。 整个程序里
tracing 0.1.44只编译一份,它的 feature 是所有依赖者要求的并集。quiet-dep要了release_max_level_info,app用的那份 tracing 也就有了。 STATIC_MAX_LEVEL是编译期常量。STATIC_MAX_LEVEL由get_max_level_inner根据 feature 算出。每个debug!展开后的第一个判断就是Level::DEBUG <= STATIC_MAX_LEVEL,两边都是常量,结果为false时整段代码在编译期被删掉,Metadata都不会进二进制。运行时的EnvFilter、with_max_level根本见不到这些事件。
release_max_level_* 只在 not(debug_assertions) 时生效,所以 dev 构建看不出问题。这条 if 链和三条规则(只在 release 生效、release 组整组优先于 max_level_*、同组取最严)在 级别过滤的几道门 里有完整的源码和实验,本页不重复。
tracing 的模块文档把这组 feature 写成给「a crate」用的配置,没有提醒库不要开。log 0.4.34 的文档对它自己的同名 feature 写得更直接:「Libraries should avoid using the max level features because they're global and can't be changed once they're set」。tracing 的这组 feature 是一样的情况。
找出是谁开的
cargo tree 的 -e features 把 feature 也画成节点,-i tracing 倒过来看「谁依赖 tracing」。在 workspace 根目录(M2 Max、cargo 随 rustc 1.99.0,路径缩短为 ./):
$ cargo tree -e features -i tracing -p app
tracing v0.1.44
├── tracing feature "attributes"
│ └── tracing feature "default"
│ ├── app v0.1.0 (./app)
│ │ └── app feature "default" (command-line)
│ └── quiet-dep v0.1.0 (./quiet-dep)
│ └── quiet-dep feature "default"
│ └── mid v0.1.0 (./mid)
│ └── mid feature "default"
│ └── app v0.1.0 (./app) (*)
├── tracing feature "default" (*)
├── tracing feature "release_max_level_info"
│ └── quiet-dep v0.1.0 (./quiet-dep) (*)
├── tracing feature "std"
│ └── tracing feature "default" (*)
└── tracing feature "tracing-attributes"
└── tracing feature "attributes" (*)
找 tracing feature "release_max_level_..."(或 "max_level_...")那一项,它下面列的就是开这个 feature 的包,这里是 quiet-dep。(*) 表示这个包的依赖链上面已经画过:quiet-dep 是经 mid 被 app 引进来的。
只想看最终启用了哪些 feature,用 -f 打印 feature 列表:
$ cargo tree -p app -i tracing -f '{p} {f}' --depth 0
tracing v0.1.44 attributes,default,release_max_level_info,std,tracing-attributes
动脑筋:在 app 里开一个更宽的级别,能不能抵消?
app/Cargo.toml 加两个 feature,分别试:
[features]
rel_trace = ["tracing/release_max_level_trace"]
max_trace = ["tracing/max_level_trace"]
cargo run -p app --release --features rel_trace 和 --features max_trace,STATIC_MAX_LEVEL 各是多少?cache miss 那行回来了吗?
修法
feature 只能加不能减,下游没有办法关掉上游开的 feature,也不能用更宽的级别覆盖它(见下面的动脑筋答案)。能做的:
- 让开 feature 的那个库去掉它。 级别上限应该由最终的二进制决定;库要在 release 里省掉日志开销,应该交给应用去开,而不是自己写进
[dependencies]。 - 在它改之前用
[patch]换掉它。 把那个库拷到本地或 fork,删掉tracing的release_max_level_*,在 workspace 根的Cargo.toml里[patch.crates-io] quiet-dep = { path = "..." }。 - 如果是你自己的库,改成让应用决定:库里不写这些 feature;应用想在 release 里删掉
debug!,就在应用自己的Cargo.toml里开release_max_level_info。
怎么确认自己没踩
看 EnvFilter 的警告。 用 EnvFilter 的程序其实已经被提醒过了。把上面 app 的 subscriber 换成 EnvFilter::from_default_env()(tracing-subscriber 加 env-filter feature),RUST_LOG=debug 跑 release(3 次输出相同;没开 tracing-subscriber 的 ansi feature,所以警告不带颜色):
warning: some trace filter directives would enable traces that are disabled statically
note: `debug` would enable the DEBUG level for all targets
note: the static max level is `info`
help: to enable DEBUG logging, remove the `max_level_info` feature from the `tracing` crate
INFO app: start
前四行是 Builder::from_directives 用 eprintln! 打到 stderr 的:任何一条指令的级别比 STATIC_MAX_LEVEL 宽,就打这段(见 EnvFilter)。它只在构造 EnvFilter 时打一次,夹在启动输出里很容易漏看。最后的 help 行要小心:它按 STATIC_MAX_LEVEL 查一张写死的表(INFO 对应 "max_level_info"),不区分 max_level_* 和 release_max_level_*,这里真正要去掉的是 release_max_level_info。前面用 with_max_level(Level::TRACE) 的那个程序就没有这段警告。
启动时打一行 STATIC_MAX_LEVEL,像前面 start 那行。release 构建里看到 info,就知道 debug! 已经不在二进制里了。
CI 里检查 tracing 的 feature 列表:
cargo tree -p app -i tracing -f '{f}' --depth 0 | grep -q max_level
在上面那个 workspace 里退出码是 0(找到了),在一个没开级别 feature 的 crate 里是 1。这一条同时匹配 max_level_* 和 release_max_level_*;应用自己有意开了某一个的话,把模式写成别的那些。
动脑筋答案
各跑 1 次(结果由 feature 在编译期决定,不随运行变化):
== release +rel_trace
INFO app: start profile="release" STATIC_MAX_LEVEL=info
INFO quiet_dep: quiet-dep working
== release +max_trace
INFO app: start profile="release" STATIC_MAX_LEVEL=info
INFO quiet_dep: quiet-dep working
两种都还是 info,cache miss 没回来。
rel_trace:两个release_max_level_*同时开,get_max_level_inner的if链从off往trace排,release_max_level_info的分支在前面,先命中,取更严的那个。max_trace:release 构建里所有release_max_level_*的分支排在所有max_level_*前面,release_max_level_info先命中,max_level_trace轮不到。
小结
- 症状:dev 构建正常,release 构建里
debug!/trace!全部消失,subscriber 和RUST_LOG怎么设都没用。 - 原因:某个依赖开了
tracing/release_max_level_*。feature 在依赖图里合并,整个程序共享一份 tracing,STATIC_MAX_LEVEL在 release 下变成那个级别,被挡住的事件在编译期就被删掉。 - 用
EnvFilter时,RUST_LOG比静态上限宽会在 stderr 打一段「disabled statically」警告,但help行写的 feature 名不分release_。 cargo tree -e features -i tracing里tracing feature "release_max_level_..."下面列的就是开它的包;cargo tree -i tracing -f '{f}' --depth 0只打印最终的 feature 列表。- 下游无法抵消:再开
release_max_level_trace或max_level_trace都不行。只能让那个库去掉它,或用[patch]换掉。 - 库不应该开这组 feature,级别上限交给应用决定。