Tracing

Recipe	Crates	Categories
Initialize the Logger
Enable Basic Tracing
Combine Layers
Configure a Custom Event Formatter
Events
Spans
Add Tracing Spans to Functions
See Also

Tracing refers to the process of capturing and recording information about the execution of a software program.

Add to Cargo.toml⮳.

[dependencies]
tracing = "0.1.41" # Or latest version
tracing-subscriber = "0.3"

Initialize the Logger

Enable Basic Tracing

fn main() {
    // Filter events at runtime using the value
    // of the RUST_LOG environment variable:
    // for example, RUST_LOG=debug,my_crate=trace
    tracing_subscriber::fmt::init();

    // This is equivalent to:
    // tracing_subscriber::fmt()
    // .with_env_filter(EnvFilter::from_default_env())
    // .init();

    tracing::info!("tracing configured!");
    println!("Done.")
}

Combine Layers

use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;

fn main() {
    tracing_subscriber::registry()
        .with(tracing_subscriber::fmt::layer())
        .with(tracing_subscriber::filter::EnvFilter::new(
            std::env::var("RUST_LOG").unwrap_or_else(|_| {
                "myproj=debug,axum=debug,tower_http=debug,mongodb=debug".into()
            }),
        ))
        .init();
    tracing::info!("tracing configured!");
    println!("Done.")
}

Or with a custom formatting layer

use tracing_subscriber::filter::EnvFilter;
use tracing_subscriber::fmt;
use tracing_subscriber::prelude::*;

fn main() {
    let fmt_layer = fmt::layer().with_target(false);
    let filter_layer = EnvFilter::try_from_default_env()
        .or_else(|_| EnvFilter::try_new("info"))
        .unwrap();

    tracing_subscriber::registry()
        .with(filter_layer)
        .with(fmt_layer)
        .init();
}

Configure a Custom Event Formatter

use tracing_subscriber::fmt;

fn main() {
    // Configure a custom event formatter
    let format = fmt::format()
        .with_level(false) // Don't include levels in formatted output
        .with_target(false) // Don't include targets
        .with_thread_ids(true) // Include the thread ID of the current thread
        .with_thread_names(true) // Include the name of the current thread
        .compact(); // Use the `Compact` formatting style.

    // Create a `fmt` subscriber that uses our custom event format, and
    // set it as the default.
    tracing_subscriber::fmt().event_format(format).init();
}

Events

use tracing::Level;
use tracing::debug;
use tracing::error;
use tracing::event;
use tracing::info;
use tracing::trace;
use tracing::warn;

#[derive(Debug)]
struct S;

fn main() {
    event!(Level::INFO, "something happened");
    error!("error!");
    warn!("warning!");
    info!("info!");
    debug!("debug info!");
    trace!("trace info!");

    event!(target: "app_events", Level::TRACE, "something has happened!");

    // Records an event with two fields (also works for spans)
    event!(
        Level::INFO,
        answer = 42,
        question = "life, the universe, and everything"
    );

    // Unlike other fields, `message`'s shorthand initialization is just
    // the string itself.
    debug!(excitement = "yay!", "hello!");

    // Shorthand for `user = user`
    let user = "ferris";
    event!(Level::TRACE, "login: {}", user);

    // Note the `?`: `my_struct` will be recorded
    // using its `fmt::Debug` implementation.
    let my_struct = S;
    event!(Level::TRACE, greeting = ?my_struct);
}

Spans

use tracing::Level;
use tracing::span;

fn main() {
    let span = span!(Level::TRACE, "my_span");
    {
        // Current lexical scope.
        let _guard = span.enter();
        println!(
            "`enter` returns a RAII guard, which, when dropped, exits the span."
        );
        println!("Any trace events that occur here will occur within the span.")
    }
    println!("Dropping the guard exits the span.");
}

One-liner with entered:

use tracing::Level;
use tracing::span;

fn main() {
    let span = span!(Level::TRACE, "some span").entered();

    println!("Code here is within the span");

    // optionally, explicitly exit the span, returning it
    let span = span.exit();

    println!("Code here is no longer within the span");

    // enter the span again
    let _span = span.entered();
    println!("Code here is within the span");
}

Holding the drop guard returned by Span::enter across .await points will result in incorrect traces. Use tracing::span::Span::in_scope⮳.

// Extension trait allowing futures to be instrumented with a tracing span,
// via `instrument(...)`
use tracing::Instrument;
use tracing::debug_span;
use tracing::info;
use tracing::info_span;

async fn my_async_function() {
    // Constructs a span at the info level:
    let span = info_span!("my_async_function_scope");
    // The above is equivalent to:
    // span!(Level::INFO, "my_async_function");

    // Executes some synchronous code in the context of this span:
    let _some_value = span.in_scope(|| {
        info!("I'm in the span!");
        42
    });
    info!("I'm not in the span!");

    // The `await` keyword may yield, causing the runtime to switch to another
    // task. However, the span has already been exited.
    some_other_async_function().await;

    // When the execution resumes from the await point, renter the span if
    // needed:
    span.in_scope(|| {
        info!("I'm also in the span!");
    });

    // We can also instrument async code:
    async move {
        // If we yield here, the span will be exited,
        // and re-entered when we resume.
        some_other_async_function().await;
        info!("I'm still in the span!");
    }
    .instrument(span) // Instrument the async block with the span...
    .await; // ...and await it.

    // We can also instrument an async function call.
    let _some_value = some_other_async_function()
        .instrument(debug_span!("some_other_async_function_scope"))
        .await;
}

async fn some_other_async_function() {}

#[tokio::main]
async fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::DEBUG)
        .init();
    my_async_function().await;
}

Add Tracing Spans to Functions

use tracing::Level;
use tracing::event;
use tracing::instrument;

#[instrument]
fn my_function(my_arg: usize) {
    // This event will be recorded inside a span named `my_function`
    // with the field `my_arg`.
    event!(Level::INFO, "inside my_function!");
    // ...
}

// Used on an async function
#[instrument(level = "info")]
async fn my_async_function() {
    // This is correct! If we yield here, the span will be exited,
    // and re-entered when we resume.
    some_other_async_function().await;
}

async fn some_other_async_function() {}

#[tokio::main]
async fn main() {
    my_function(42);
    my_async_function().await;
}

See Also

tracing_journald⮳ provides support for logging tracing⮳ events natively to journald⮳, preserving any structured information.