Logging and tracing in Rust: what developers should know

Logging and tracing in Rust: what developers should know

In production systems, visibility into application behavior often determines how quickly you diagnose issues and understand performance bottlenecks. Rust's ecosystem provides powerful tools for structured logging and distributed tracing, but they work differently from traditional logging in other languages. This guide walks you through the core concepts and practical patterns that teams use to instrument their applications effectively.

Why structured logging matters

Traditional logging—concatenating strings and writing them to stdout—gives you text, not data. When you log "user 123 purchased item 456 for $99.99", a log aggregator sees a blob of text. Extracting metrics, alerting on patterns, or correlating events across services becomes tedious and error-prone.

Structured logging captures events as key-value pairs that systems can parse, index, and query reliably. When you emit user_id=123, item_id=456, amount_cents=9999, your aggregator can slice, filter, and correlate in seconds. In microservice architectures processing thousands of requests per second, this shift from text to structured data is non-negotiable.

The tracing crate — Structured events and spans

Rust's tracing crate is the foundation for structured diagnostics. It provides two core abstractions: events and spans.

Events are point-in-time occurrences with associated fields. Spans are intervals of time with a name and fields; they track the lifespan of operations like HTTP requests, database queries, or async tasks.

Let's see this in practice. Suppose we're building a payment service:

use tracing::{event, Level, span};

fn process_payment(user_id: u64, amount_cents: u64) -> Result<String, &'static str> {
    let span = span!(Level::INFO, "process_payment", %user_id, %amount_cents);
    let _enter = span.enter();

    event!(Level::INFO, "validating payment");
    if amount_cents == 0 {
        event!(Level::WARN, "zero amount attempted");
        return Err("Invalid amount");
    }

    event!(Level::INFO, "charging card");
    // ... charge logic ...

    event!(Level::INFO, "payment successful", transaction_id = "txn_xyz");
    Ok("txn_xyz".to_string())
}

Here, span! creates a span with the name process_payment and fields user_id and amount_cents. The _enter guard keeps the span active. All events emitted while the span is entered are linked to it.

The % prefix uses the Display implementation; ? uses Debug. Without a prefix, the crate tries Debug. This syntax keeps field capture concise.

Spans nest naturally, mirroring call stacks:

fn request_handler(req: &Request) {
    let span = span!(Level::INFO, "http_request", method = %req.method, path = %req.path);
    let _enter = span.enter();

    // Nested span
    let db_span = span!(Level::DEBUG, "database_query", table = "payments");
    let _db_enter = db_span.enter();
    // ... query ...
    drop(_db_enter);

    // Back to request span
    event!(Level::INFO, "request completed");
}

When the logs are rendered, nested spans show the relationship, helping you trace execution flow across your application.

Subscriber — Formatting and filtering logs

Emitting events and spans is only half the story. A subscriber consumes them and decides what to do: write to stderr, send to a file, or ship to a log aggregator.

The tracing-subscriber crate provides builders for common setups. Here's a typical pattern:

use tracing_subscriber::{fmt, prelude::*, EnvFilter};

fn main() {
    tracing_subscriber::registry()
        .with(EnvFilter::from_default_env())
        .with(fmt::layer().with_writer(std::io::stdout))
        .init();

    // Your app runs here
}

This creates a subscriber that:

• Respects RUST_LOG environment variable for filtering (e.g., RUST_LOG=debug,myapp::payment=trace).
• Formats events and spans as pretty-printed text to stdout.
• Initializes globally so all code using tracing macros feeds into it.

For JSON output (preferred in containerized environments), swap the layer:

use tracing_subscriber::fmt;

tracing_subscriber::registry()
    .with(EnvFilter::from_default_env())
    .with(fmt::layer().json())
    .init();

Now each event and span becomes a JSON object with fields, timestamps, and target module. Aggregators parse this natively.

You can layer multiple subscribers to, say, send errors to a dedicated error channel while general logs go to stdout:

use tracing_subscriber::{fmt, filter};

let error_layer = fmt::layer()
    .json()
    .with_filter(filter::LevelFilter::ERROR);

let info_layer = fmt::layer()
    .pretty()
    .with_filter(filter::LevelFilter::INFO);

tracing_subscriber::registry()
    .with(error_layer)
    .with(info_layer)
    .init();

Instrument — Automatic span decoration

Manually entering and exiting spans is tedious. The #[instrument] macro automates this pattern for functions:

use tracing::instrument;

#[instrument]
async fn fetch_user(user_id: u64) -> Result<User, DbError> {
    // Automatically creates a span named "fetch_user" with field user_id
    let user = db.query("SELECT * FROM users WHERE id = ?", user_id).await?;
    event!(Level::INFO, "user retrieved");
    Ok(user)
}

The macro generates a span with the function name and captures all arguments as fields. If an argument doesn't implement Debug, exclude it with #[instrument(skip(arg_name))]:

#[instrument(skip(secret_key))]
fn validate_jwt(token: &str, secret_key: &[u8]) -> Result<Claims, JwtError> {
    // Span captures token but not secret_key
    // ...
}

For async code, #[instrument] automatically wraps the future, preserving span context across await points—critical for tracing async workloads:

#[instrument(skip(pool))]
async fn process_orders(pool: &PgPool, batch_size: usize) -> Result<usize, Error> {
    let orders = pool.fetch_many("SELECT * FROM orders WHERE status = 'pending' LIMIT ?", batch_size).await?;
    for order in orders {
        handle_order(order).await?;
    }
    Ok(orders.len())
}

#[instrument(skip(order))]
async fn handle_order(order: Order) -> Result<(), Error> {
    // Span context flows correctly even though we're in a loop
    charge_payment(&order).await?;
    Ok(())
}

OpenTelemetry — Export traces to collectors

For distributed systems, local logs aren't enough. You need a way to send traces to a central collector like Jaeger, Datadog, or Grafana Loki. OpenTelemetry is the standardized protocol for this.

The tracing-opentelemetry crate bridges Rust's tracing to the OpenTelemetry standard:

use opentelemetry::global;
use tracing_opentelemetry::OpenTelemetryLayer;
use tracing_subscriber::prelude::*;

fn main() {
    // Initialize the OpenTelemetry exporter (e.g., to Jaeger)
    let tracer = opentelemetry_jaeger::new_pipeline()
        .install_simple()
        .expect("Failed to install OpenTelemetry tracer");

    // Create a layer that sends traces to OpenTelemetry
    let otel_layer = OpenTelemetryLayer::new(tracer);

    // Combine with regular logging
    tracing_subscriber::registry()
        .with(otel_layer)
        .with(tracing_subscriber::fmt::layer())
        .init();

    // Your app code
}

Now every span and event flows to Jaeger. You can visualize trace latencies, identify bottlenecks, and correlate across microservices using trace IDs that propagate automatically through tracing's context.

In a typical setup, a frontend service makes an HTTP request; the request handler creates a root span. When the handler calls a backend service, tracing injects the trace ID into HTTP headers. The backend extracts it and links its spans to the same trace. Jaeger then shows the entire distributed flow in one view.

use opentelemetry::propagation::Injector;
use opentelemetry_jaeger::SpanExportError;

async fn call_backend(client: &HttpClient) -> Result<Response, Error> {
    let span = tracing::info_span!("backend_call", endpoint = "/api/users");
    let _enter = span.enter();

    let mut req = client.get("http://backend:8080/api/users");
    
    // Inject trace context into HTTP headers
    let mut propagator = opentelemetry::global::get_text_map_propagator(|p| p.clone());
    propagator.inject_context(
        &tracing::Span::current().context(),
        &mut HeaderInjector(&mut req),
    );

    req.send().await
}

struct HeaderInjector<'a>(&'a mut HttpRequest);

impl<'a> Injector for HeaderInjector<'a> {
    fn set(&mut self, key: &str, value: String) {
        self.0.header(key, value);
    }
}

Common mistakes

1. Over-logging in hot paths: Emitting a trace for every database row or API call can overwhelm your system. Use sampling in OpenTelemetry or filter at the subscriber level. In high-throughput scenarios, only trace a percentage of requests:

use opentelemetry::sdk::trace::Sampler;

let sampler = opentelemetry::sdk::trace::Sampler::ParentBased(Box::new(
    opentelemetry::sdk::trace::Sampler::TraceIdRatioBased(0.1), // 10% sampling
));

let tracer = opentelemetry_jaeger::new_pipeline()
    .with_sampler(sampler)
    .install_simple()?;

2. Capturing sensitive data in fields: API keys, passwords, and PII end up in logs. Always skip sensitive arguments or sanitize them post-capture. Use the skip attribute liberally.

3. Forgetting to initialize the subscriber: If you call tracing::info!() without initializing a subscriber, events are silently dropped. Always call `.init()` or `.try_init()` early in main().

4. Mixing dynamic and static field names: tracing prefers static field names for aggregator indexing. Avoid code like event!(Level::INFO, "{}", key = value) where key is a string. Use predefined fields instead.

5. Not handling trace context propagation in background tasks: If you spawn a task with tokio::spawn, trace context is lost unless you explicitly instrument it:

use tracing::Instrument;

tokio::spawn(
    async {
        // This inherits the parent span
    }
    .instrument(tracing::info_span!("background_task")),
);

Key takeaways

• Structured logging with tracing gives you queryable, correlated data instead of unstructured text.
• Spans track intervals and nest naturally; events mark points in time. Use both to paint a complete picture.
• #[instrument] eliminates boilerplate by automatically wrapping functions in spans, especially powerful for async code.
• tracing-subscriber lets you compose multiple layers (JSON, filtering, levels) and route logs to different destinations.
• OpenTelemetry integration enables distributed tracing across microservices, with trace IDs flowing automatically through headers.
• Sample high-volume traces, skip sensitive fields, and always initialize your subscriber globally in main().