任务追踪入门

 tracing 板块是 Rust 程序的工具框架，用于收集结构和事件的诊断信息。

在 Tokio 这样的异步系统中，解释传统日志信息往往具有相当大的挑战性。由于单个任务在同一线程上多路复用，相关事件和日志行相互混合，因此很难跟踪逻辑流。与日志信息不同，tracing中的Span有开始和结束时间，可由执行流进入和退出，并可存在于类似 spans 的嵌套树中，tracing扩展了日志式诊断，允许库和应用程序记录结构化事件，并提供有关时间性和起因的附加信息。为了表示在某一时刻发生的事情，tracing提供了 事件 的补充概念。 Span和Event都是 结构化的 ，能够记录键入数据和文本信息。

可以使用 tracing 来：

• 向 OpenTelemetry 收集器发送分布式跟踪信息
• 使用 Tokio Console 调试应用程序
• 将日志记录到 stdout、日志文件 或 journald。
• 配置文件查询应用程序花费时间

VeryAUX 翻译于 7个月前

0 重译

Setup

To begin, add tracing and tracing-subscriber as dependencies:

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

The tracing crate provides the API we will use to emit traces. The tracing-subscriber crate provides some basic utilities for forwarding those traces to external listeners (e.g., stdout).

Subscribing to Traces

If you are authoring an executable (as opposed to a library), you will need to register a tracing subscriber. Subscribers are types that process traces emitted by your application and its dependencies, and and can perform tasks such as computing metrics, monitoring for errors, and re-emitting traces to the outside world (e.g., journald, stdout, or an open-telemetry daemon).

In most circumstances, you should register your tracing subscriber as early as possible in your main function. For instance, the FmtSubscriber type provided by tracing-subscriber prints formatted traces and events to stdout, can be registered like so:

#[tokio::main]
pub async fn main() -> mini_redis::Result<()> {
    // construct a subscriber that prints formatted traces to stdout
    let subscriber = tracing_subscriber::FmtSubscriber::new();
    // use that subscriber to process traces emitted after this point
    tracing::subscriber::set_global_default(subscriber)?;
    ...
}

If you run your application now, you may see some trace events emitted by Tokio, but you will need to modify your own application to emit traces to get the most out of tracing.

Subscriber Configuration

In the above example, we've configured FmtSubscriber with its default configuration. However, tracing-subscriber also provides a number of ways to configure the FmtSubscriber's behavior, such as customizing the output format, including additional information (such as thread IDs or source code locations) in the logs, and writing the logs to somewhere other than stdout.

For example:

// Start configuring a `fmt` subscriber
let subscriber = tracing_subscriber::fmt()
    // Use a more compact, abbreviated log format
    .compact()
    // Display source code file paths
    .with_file(true)
    // Display source code line numbers
    .with_line_number(true)
    // Display the thread ID an event was recorded on
    .with_thread_ids(true)
    // Don't display the event's target (module path)
    .with_target(false)
    // Build the subscriber
    .finish();

For details on the available configuration options, see the tracing_subscriber::fmt documentation.

In addition to the FmtSubscriber type from tracing-subscriber, other Subscribers can implement their own ways of recording tracing data. This includes alternative output formats, analysis and aggregation, and integration with other systems such as distributed tracing or log aggregation services. A number of crates provide additional Subscriber implementations that may be of interest. See here for an (incomplete) list of additional Subscriber implementations.

Finally, in some cases, it may be useful to combine multiple different ways of recording traces together to build a single Subscriber that implements multiple behaviors. For this purpose, the tracing-subscriber crate provides a Layer trait that represents a component that may be composed together with other Layers to form a Subscriber. See here for details on using Layers.

Emitting Spans and Events

The easiest way to emit spans is with the instrument proc-macro annotation provided by tracing, which re-writes the bodies of functions to emit spans each time they are invoked; e.g.:

#[tracing::instrument]
fn trace_me(a: u32, b: u32) -> u32 {
    a + b
}

Each invocation of trace_me will emit a tracing Span that:

1. has a verbosity level of trace (the greatest verbosity),
2. is named trace_me,
3. has fields a and b, whose values are the arguments of trace_me

The instrument attribute is highly configurable; e.g., to trace the method in mini-redis-server that handles each connection:

use tracing::instrument;

impl Handler {
    /// Process a single connection.
    #[instrument(
        level = "info",
        name = "Handler::run",
        skip(self),
        fields(
            // `%` serializes the peer IP addr with `Display`
            peer_addr = %self.connection.peer_addr().unwrap()
        ),
    )]
    async fn run(&mut self) -> mini_redis::Result<()> {
        ...
    }
}

mini-redis-server will now emit a tracing Span for each incoming connection that:

1. has a verbosity level of info (the "middle ground" verbosity),
2. is named Handler::run,
3. has some structured data associated with it.
   • fields(...) indicates that emitted span should include the fmt::Display representation of the connection's SocketAddr in a field called peer_addr.
   • skip(self) indicates that emitted span should not record Hander's debug representation.

You can also construct a Span manually by invoking the span! macro, or any of its leveled shorthands (error_span!, warn_span!, info_span!, debug_span!, trace_span!).

To emit events, invoke the event! macro, or any of its leveled shorthands (error!, warn!, info!, debug!, trace!). For instance, to log that a client sent a malformed command:

// Convert the redis frame into a command struct. This returns an
// error if the frame is not a valid redis command.
let cmd = match Command::from_frame(frame) {
    Ok(cmd) => cmd,
    Err(cause) => {
        // The frame was malformed and could not be parsed. This is
        // probably indicative of an issue with the client (as opposed
        // to our server), so we (1) emit a warning...
        //
        // The syntax here is a shorthand provided by the `tracing`
        // crate. It can be thought of as similar to:
        //      tracing::warn! {
        //          cause = format!("{}", cause),
        //          "failed to parse command from frame"
        //      };
        // `tracing` provides structured logging, so information is
        // "logged" as key-value pairs.
        tracing::warn! {
            %cause,
            "failed to parse command from frame"
        };
        // ...and (2) respond to the client with the error:
        Command::from_error(cause)
    }
};

If you run your application, you now will see events decorated with their span's context emitted for each incoming connection that it processes.