Agent skill

rust-tracing

Rust tracing and structured logging with the tracing ecosystem. Use when adding logging, instrumenting functions, setting up observability, configuring log output, or debugging with traces.

Stars 163
Forks 31

Install this agent skill to your Project

npx add-skill https://github.com/majiayu000/claude-skill-registry/tree/main/skills/development/rust-tracing

SKILL.md

Rust Tracing and Structured Logging

Comprehensive guide for observability with the tracing ecosystem.

Setup

Basic Setup

toml
# Cargo.toml
[dependencies]
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
rust
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter};

fn init_tracing() {
    tracing_subscriber::registry()
        .with(EnvFilter::try_from_default_env().unwrap_or_else(|_| {
            // Default log level
            "info,nebula=debug,tower_http=debug".into()
        }))
        .with(tracing_subscriber::fmt::layer())
        .init();
}

fn main() {
    init_tracing();
    // ...
}

Production Setup with JSON

rust
use tracing_subscriber::{
    fmt::{self, format::FmtSpan},
    layer::SubscriberExt,
    util::SubscriberInitExt,
    EnvFilter,
};

fn init_production_tracing() {
    let env_filter = EnvFilter::try_from_default_env()
        .unwrap_or_else(|_| "info".into());

    let fmt_layer = fmt::layer()
        .json()                           // JSON output for log aggregation
        .with_current_span(true)          // Include current span
        .with_span_list(true)             // Include span hierarchy
        .with_file(true)                  // Include file name
        .with_line_number(true)           // Include line number
        .with_thread_ids(true)            // Include thread ID
        .with_target(true);               // Include target module

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

Development Setup with Pretty Output

rust
fn init_dev_tracing() {
    tracing_subscriber::registry()
        .with(EnvFilter::try_from_default_env().unwrap_or_else(|_| "debug".into()))
        .with(
            tracing_subscriber::fmt::layer()
                .pretty()                  // Human-readable output
                .with_file(true)
                .with_line_number(true)
                .with_thread_names(true)
        )
        .init();
}

Log Levels

Choosing the Right Level

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

fn process_request(req: &Request) -> Result<Response, Error> {
    // TRACE: Very detailed debugging, high volume
    trace!(headers = ?req.headers(), "Raw request headers");
    
    // DEBUG: Diagnostic information for debugging
    debug!(method = %req.method(), path = %req.path(), "Processing request");
    
    // INFO: Notable events in normal operation
    info!(user_id = %user.id, "User authenticated successfully");
    
    // WARN: Unexpected but recoverable situations
    warn!(retry_count = 3, "Request failed, retrying");
    
    // ERROR: Failures that need attention
    error!(error = ?err, "Failed to process request");
    
    Ok(response)
}

Level Guidelines

Level When to Use Examples
error Failures requiring immediate attention DB connection lost, unhandled errors
warn Unexpected but handled situations Retry succeeded, deprecated API used
info Notable business events User login, request completed, job started
debug Diagnostic information Request details, internal state
trace Very detailed debugging Loop iterations, raw data

Structured Fields

Field Types

rust
use tracing::info;

fn log_examples() {
    let user_id = 42;
    let username = "alice";
    let request = Request::new();
    
    // Display formatting (uses Display trait)
    info!(%user_id, "User action");  // user_id=42
    
    // Debug formatting (uses Debug trait)
    info!(?request, "Request received");  // request=Request { ... }
    
    // Named fields
    info!(user.id = user_id, user.name = username, "User logged in");
    
    // Literal values
    info!(version = 1, "API version");
    
    // Empty message with just fields
    info!(user_id, action = "login");
}

Consistent Field Naming

rust
// Use consistent, hierarchical field names across the codebase

// Request context
info!(
    request.id = %request_id,
    request.method = %method,
    request.path = %path,
    "Handling request"
);

// User context
info!(
    user.id = %user_id,
    user.role = %role,
    "User action"
);

// Database operations
debug!(
    db.query = query,
    db.duration_ms = duration.as_millis(),
    db.rows_affected = rows,
    "Query executed"
);

// External service calls
info!(
    service.name = "payment-api",
    service.operation = "charge",
    service.duration_ms = duration.as_millis(),
    "External call completed"
);

// Error context
error!(
    error.kind = %err.kind(),
    error.message = %err,
    error.source = ?err.source(),
    "Operation failed"
);

Spans

Function Instrumentation

rust
use tracing::{instrument, info, debug, Span};

// Basic instrumentation
#[instrument]
fn process_item(item_id: u64) -> Result<(), Error> {
    info!("Processing started");
    // All logs here are within the span
    do_work()?;
    info!("Processing completed");
    Ok(())
}

// Skip sensitive fields
#[instrument(skip(password, api_key))]
fn authenticate(username: &str, password: &str, api_key: &str) -> Result<User, AuthError> {
    info!("Authentication attempt");
    // password and api_key won't be logged
    Ok(user)
}

// Custom span name and level
#[instrument(name = "handle_request", level = "info")]
async fn handle(req: Request) -> Response {
    // ...
}

// Add custom fields
#[instrument(fields(request_id = %generate_id()))]
async fn process_request(req: Request) -> Response {
    // ...
}

// Skip all parameters, add specific ones
#[instrument(skip_all, fields(user_id = %user.id, action = "update"))]
fn update_user(user: &User, data: UpdateData) -> Result<(), Error> {
    // ...
}

Manual Spans

rust
use tracing::{span, Level, info, Instrument};

async fn complex_operation() {
    // Create a span
    let span = span!(Level::INFO, "complex_operation", phase = "init");
    let _guard = span.enter();
    
    info!("Starting phase 1");
    
    // Nested span
    {
        let inner_span = span!(Level::DEBUG, "phase_1");
        let _inner_guard = inner_span.enter();
        do_phase_1().await;
    }
    
    // Update span fields
    Span::current().record("phase", "complete");
    info!("All phases complete");
}

// For async code, use .instrument()
async fn async_operation() {
    let span = span!(Level::INFO, "async_op");
    
    async move {
        info!("Inside async operation");
        do_async_work().await;
    }
    .instrument(span)
    .await;
}

Span Events

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

fn with_span_events() {
    let span = span!(Level::INFO, "operation");
    let _guard = span.enter();
    
    // Event within span
    event!(Level::INFO, "Operation started");
    
    // Event with fields
    event!(Level::DEBUG, items = 42, "Processing items");
    
    // Parent span is automatically included
}

Async Tracing

Instrument Async Functions

rust
use tracing::{instrument, info, Instrument};
use std::future::Future;

#[instrument]
async fn fetch_data(url: &str) -> Result<Data, Error> {
    info!("Fetching data");
    let response = client.get(url).await?;
    info!(status = %response.status(), "Response received");
    Ok(response.json().await?)
}

// For closures
async fn process_items(items: Vec<Item>) {
    let futures = items.into_iter().map(|item| {
        let span = tracing::info_span!("process_item", item_id = %item.id);
        async move {
            process(item).await
        }
        .instrument(span)
    });
    
    futures::future::join_all(futures).await;
}

Tokio Console Integration

toml
# Cargo.toml
[dependencies]
console-subscriber = "0.4"
tokio = { version = "1", features = ["full", "tracing"] }
rust
fn init_with_console() {
    console_subscriber::init();  // For tokio-console debugging
}

Request Tracing

HTTP Request Spans

rust
use axum::{
    extract::Request,
    middleware::Next,
    response::Response,
};
use tracing::{info_span, Instrument};
use uuid::Uuid;

pub async fn trace_request(request: Request, next: Next) -> Response {
    let request_id = Uuid::new_v4();
    let method = request.method().clone();
    let uri = request.uri().clone();
    
    let span = info_span!(
        "http_request",
        request.id = %request_id,
        request.method = %method,
        request.path = %uri.path(),
        request.query = ?uri.query(),
        response.status = tracing::field::Empty,
        response.duration_ms = tracing::field::Empty,
    );
    
    async move {
        let start = std::time::Instant::now();
        let response = next.run(request).await;
        let duration = start.elapsed();
        
        // Record response fields
        tracing::Span::current()
            .record("response.status", response.status().as_u16())
            .record("response.duration_ms", duration.as_millis() as u64);
        
        tracing::info!("Request completed");
        
        response
    }
    .instrument(span)
    .await
}

Tower HTTP Tracing

rust
use axum::Router;
use tower_http::trace::{self, TraceLayer};
use tracing::Level;

fn create_router() -> Router {
    Router::new()
        .route("/", get(handler))
        .layer(
            TraceLayer::new_for_http()
                .make_span_with(trace::DefaultMakeSpan::new().level(Level::INFO))
                .on_request(trace::DefaultOnRequest::new().level(Level::INFO))
                .on_response(trace::DefaultOnResponse::new().level(Level::INFO))
                .on_failure(trace::DefaultOnFailure::new().level(Level::ERROR))
        )
}

Error Tracing

Logging Errors

rust
use tracing::{error, warn, instrument};

#[instrument(err)]  // Automatically logs errors at ERROR level
fn fallible_operation() -> Result<(), Error> {
    do_something()?;
    Ok(())
}

#[instrument(err(level = "warn"))]  // Log errors at WARN level
fn recoverable_operation() -> Result<(), Error> {
    // ...
}

// Manual error logging with context
fn process() -> Result<Output, Error> {
    match do_work() {
        Ok(result) => Ok(result),
        Err(e) => {
            error!(
                error = %e,
                error.kind = ?e.kind(),
                "Operation failed"
            );
            Err(e)
        }
    }
}

// Chain of errors
fn with_error_chain() {
    if let Err(e) = operation() {
        error!(error = ?e, "Top-level error");
        
        let mut source = e.source();
        while let Some(cause) = source {
            error!(cause = %cause, "Caused by");
            source = cause.source();
        }
    }
}

Filtering and Output

Environment Filter Syntax

bash
# Set via environment variable
RUST_LOG=info                           # All modules at INFO
RUST_LOG=debug,hyper=info               # Default DEBUG, hyper at INFO
RUST_LOG=nebula=debug,tower_http=debug  # Specific modules
RUST_LOG=nebula::api=trace              # Specific path
RUST_LOG="info,nebula[user_id]=debug"   # Filter by span field

Programmatic Filtering

rust
use tracing_subscriber::{filter, layer::SubscriberExt, util::SubscriberInitExt};

fn init_filtered() {
    let filter = filter::Targets::new()
        .with_default(tracing::Level::INFO)
        .with_target("nebula", tracing::Level::DEBUG)
        .with_target("hyper", tracing::Level::WARN)
        .with_target("tower_http", tracing::Level::DEBUG);
    
    tracing_subscriber::registry()
        .with(tracing_subscriber::fmt::layer())
        .with(filter)
        .init();
}

Multiple Outputs

rust
use tracing_subscriber::{
    fmt::{self, writer::MakeWriterExt},
    layer::SubscriberExt,
    util::SubscriberInitExt,
};
use std::io;

fn init_multi_output() {
    // Stderr for errors, stdout for everything else
    let stderr = io::stderr.with_max_level(tracing::Level::WARN);
    let stdout = io::stdout.with_max_level(tracing::Level::INFO);
    
    tracing_subscriber::registry()
        .with(fmt::layer().with_writer(stderr))
        .with(fmt::layer().with_writer(stdout))
        .init();
}

OpenTelemetry Integration

Setup with Jaeger

toml
[dependencies]
opentelemetry = "0.27"
opentelemetry_sdk = { version = "0.27", features = ["rt-tokio"] }
opentelemetry-otlp = "0.27"
tracing-opentelemetry = "0.28"
rust
use opentelemetry::trace::TracerProvider;
use opentelemetry_sdk::trace::SdkTracerProvider;
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};

fn init_otel() -> Result<SdkTracerProvider, Box<dyn std::error::Error>> {
    let exporter = opentelemetry_otlp::SpanExporter::builder()
        .with_tonic()
        .build()?;
    
    let provider = SdkTracerProvider::builder()
        .with_batch_exporter(exporter)
        .build();
    
    let tracer = provider.tracer("nebula");
    let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);
    
    tracing_subscriber::registry()
        .with(telemetry)
        .with(tracing_subscriber::fmt::layer())
        .init();
    
    Ok(provider)
}

// Shutdown properly
async fn shutdown(provider: SdkTracerProvider) {
    provider.shutdown().expect("Failed to shutdown tracer");
}

Testing

Capturing Logs in Tests

rust
#[cfg(test)]
mod tests {
    use tracing_test::traced_test;
    
    #[traced_test]
    #[test]
    fn test_with_logs() {
        tracing::info!("This will be captured");
        assert!(logs_contain("captured"));
    }
    
    #[traced_test]
    #[tokio::test]
    async fn test_async_with_logs() {
        tracing::debug!("Async test log");
        assert!(logs_contain("Async test"));
    }
}

Test Subscriber

rust
use tracing_subscriber::fmt::MakeWriter;
use std::sync::{Arc, Mutex};

struct TestWriter {
    logs: Arc<Mutex<Vec<String>>>,
}

impl std::io::Write for TestWriter {
    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
        let log = String::from_utf8_lossy(buf).to_string();
        self.logs.lock().unwrap().push(log);
        Ok(buf.len())
    }
    
    fn flush(&mut self) -> std::io::Result<()> {
        Ok(())
    }
}

#[test]
fn test_logging() {
    let logs = Arc::new(Mutex::new(Vec::new()));
    let writer = TestWriter { logs: logs.clone() };
    
    let subscriber = tracing_subscriber::fmt()
        .with_writer(move || writer.clone())
        .finish();
    
    tracing::subscriber::with_default(subscriber, || {
        tracing::info!("Test message");
    });
    
    let captured = logs.lock().unwrap();
    assert!(captured.iter().any(|l| l.contains("Test message")));
}

Nebula Conventions

Standard Span Names

rust
// HTTP requests
#[instrument(name = "http.request")]

// Database operations
#[instrument(name = "db.query")]
#[instrument(name = "db.transaction")]

// Background jobs
#[instrument(name = "job.execute")]

// Workflow operations
#[instrument(name = "workflow.run")]
#[instrument(name = "workflow.step")]

// External services
#[instrument(name = "external.call")]

Standard Field Names

rust
// Request context
request.id
request.method
request.path

// Response context
response.status
response.duration_ms

// User context
user.id
user.role

// Workflow context
workflow.id
workflow.name
workflow.step

// Database context
db.query
db.table
db.duration_ms
db.rows_affected

// Error context
error.kind
error.message
error.code

Log Message Style

rust
// Use lowercase, present tense, no trailing punctuation
info!("processing request");           // Good
info!("Processing Request.");          // Bad

// Include context in fields, not message
info!(user_id = %id, "user logged in");  // Good
info!("User {} logged in", id);           // Less structured

// Be specific
info!("workflow step completed");         // Good
info!("done");                            // Too vague

Didn't find tool you were looking for?

Be as detailed as possible for better results