如何使用Rust tracing记录Span的持续时间？

你可以完全不依赖第三方工具，通过tracing本身的扩展机制实现简单的span持续时间记录，以下是两种实用方案：

方案一：自定义轻量Subscriber #

通过实现tracing::Subscriber trait，直接在span创建和退出时记录时间并计算时长：

依赖配置 #

[dependencies]
tracing = "0.1"
tracing-core = "0.1"

完整代码示例 #

use std::time::Instant;
use tracing::{span, Subscriber};
use tracing_core::{
    metadata::Metadata,
    span::{Attributes, Id, Record},
    Event,
};

// 自定义Subscriber，存储每个span的开始时间和名称
struct DurationSubscriber {
    span_data: std::collections::HashMap<Id, (Instant, String)>,
}

impl DurationSubscriber {
    fn new() -> Self {
        Self {
            span_data: std::collections::HashMap::new(),
        }
    }
}

impl Subscriber for DurationSubscriber {
    // 控制哪些span需要被记录，这里默认全部记录
    fn enabled(&self, _metadata: &Metadata<'_>) -> bool {
        true
    }

    // span创建时记录开始时间和名称
    fn new_span(&self, attrs: &Attributes<'_>) -> Id {
        let id = Id::from_u64(self.span_data.len() as u64 + 1);
        let span_name = attrs.metadata().name().to_string();
        self.span_data.insert(id.clone(), (Instant::now(), span_name));
        id
    }

    // span退出时计算并打印持续时间
    fn exit(&self, span: &Id) {
        if let Some((start_time, name)) = self.span_data.get(span) {
            let duration = start_time.elapsed();
            println!("{}: {:?}", name, duration);
            // 可选：移除已结束的span数据，节省内存
            // self.span_data.remove(span);
        }
    }

    // 以下方法为默认空实现，无需修改
    fn record(&self, _span: &Id, _values: &Record<'_>) {}
    fn record_follows_from(&self, _span: &Id, _follows: &Id) {}
    fn event(&self, _event: &Event<'_>) {}
    fn enter(&self, _span: &Id) {}
}

// 使用示例
fn main() {
    // 全局注册自定义Subscriber
    tracing::subscriber::set_global_default(DurationSubscriber::new()).unwrap();

    let root = tracing::info_span!("根操作");
    let _enter_root = root.enter();
    std::thread::sleep(std::time::Duration::from_millis(150));

    {
        let child = tracing::debug_span!("子任务");
        let _enter_child = child.enter();
        std::thread::sleep(std::time::Duration::from_millis(80));
    }

    std::thread::sleep(std::time::Duration::from_millis(100));
}

自定义调整 #

• 若不需要记录所有span，可修改enabled方法，比如只保留Level::INFO及以上的span
• 可以调整输出格式，比如只输出时长数值，或添加时间戳

方案二：基于tracing-subscriber的Layer #

如果需要和其他tracing生态组件（比如日志输出）配合，推荐使用Layer机制，更灵活：

依赖配置 #

[dependencies]
tracing = "0.1"
tracing-subscriber = "0.3"

完整代码示例 #

use std::time::Instant;
use tracing_subscriber::{layer::Layer, registry::LookupSpan, util::SubscriberInitExt, Registry};

// 自定义Layer，用于记录span时长
#[derive(Debug, Default)]
struct DurationLayer;

impl<S> Layer<S> for DurationLayer
where
    S: tracing::Subscriber + for<'a> LookupSpan<'a>,
{
    // span创建时，将开始时间存入span的扩展数据
    fn on_new_span(&self, _attrs: &tracing::span::Attributes<'_>, id: &tracing::span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) {
        let span = ctx.span(id).unwrap();
        span.extensions_mut().insert(Instant::now());
    }

    // span关闭时，计算并打印时长
    fn on_close(&self, id: &tracing::span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) {
        let span = ctx.span(id).unwrap();
        if let Some(start_time) = span.extensions().get::<Instant>() {
            let duration = start_time.elapsed();
            println!("{}: {:?}", span.name(), duration);
        }
    }
}

// 使用示例
fn main() {
    // 注册Layer到Registry，可同时添加其他Layer（比如日志层）
    Registry::default().with(DurationLayer).init();

    let root = tracing::info_span!("根操作");
    let _enter_root = root.enter();
    std::thread::sleep(std::time::Duration::from_millis(150));

    {
        let child = tracing::debug_span!("子任务");
        let _enter_child = child.enter();
        std::thread::sleep(std::time::Duration::from_millis(80));
    }

    std::thread::sleep(std::time::Duration::from_millis(100));
}

方案优势 #

• 可以和tracing-subscriber的其他Layer（比如fmt日志层）组合使用，同时输出日志和时长
• 无需完全自定义Subscriber，复用tracing生态的基础能力

总结 #

以上两种方案都能满足你的需求：仅记录span的纯持续时间，不需要直方图或树形结构输出，且完全基于tracing本身的机制实现，无需依赖额外工具库。

内容的提问来源于stack exchange，提问作者alextes