Tracing Spans and Events Explained for Beginners Made Clear

A log line says that something happened. A trace says what was going on around it. The tracing crate adds the second by letting you wrap work in spans. Everything compiles on Rust 1.90 with edition 2024, tracing 0.1 and tracing-subscriber 0.3 (feature env-filter).

Events

use tracing::{debug, error, info, warn};

fn main() {
    tracing_subscriber::fmt::init();

    info!("starting");
    debug!(retries = 3, "config loaded");
    warn!(path = %"/tmp/x", "file missing, using default");
    error!(code = 500, "request failed");
}

2025-01-01T12:00:00.000000Z  INFO app: starting
2025-01-01T12:00:00.000100Z  WARN app: file missing, using default path=/tmp/x
2025-01-01T12:00:00.000120Z ERROR app: request failed code=500

The timestamps vary. debug! is filtered out by default; run with RUST_LOG=debug to see it. Fields use name = value; the % sigil formats with Display and ? with Debug. Fields are data a log system can index, which strings cannot give.

Spans

use tracing::{info, info_span};

fn handle(id: u32) {
    let span = info_span!("request", id);
    let _guard = span.enter();

    info!("looking up user");
    lookup(id);
    info!("done");
}

fn lookup(id: u32) {
    info!(found = id % 2 == 0, "lookup finished");
}

fn main() {
    tracing_subscriber::fmt::init();
    handle(7);
}

 INFO request{id=7}: app: looking up user
 INFO request{id=7}: app: lookup finished found=false
 INFO request{id=7}: app: done

Every event inside the span, including the one in lookup, carries request{id=7}. When requests interleave, you can still tell them apart.

instrument

use tracing::{info, instrument};

#[instrument(skip(password))]
fn login(user: &str, password: &str) -> bool {
    info!("checking credentials");
    !password.is_empty()
}

fn main() {
    tracing_subscriber::fmt::init();
    login("ada", "secret");
}

#[instrument] makes a span named after the function and records the arguments as fields. skip(password) keeps a secret out of logs, which you must do by hand: instrument records every argument that implements Debug unless told otherwise (logging without leaking secrets). On async fn it works too, and the span follows the future across threads, which is why it replaces manual request ids (Axum request ids).

Subscribers and filters

A subscriber decides what happens to events: print them, write JSON, send to an exporter.

use tracing_subscriber::{fmt, EnvFilter};

fn init() {
    tracing_subscriber::fmt()
        .with_env_filter(EnvFilter::from_default_env().add_directive("info".parse().unwrap()))
        .with_target(false)
        .init();
}

RUST_LOG=app=debug,hyper=warn,info means debug for your crate, warn for hyper, info for everything else. Install one subscriber, once, in main; libraries only emit events.

Levels

The guidance on choosing is in log levels, and the earlier crate in logging with log and env_logger. The structured approach for services is in structured logging with tracing.