Library

tracing

Overview

tracing is a modern Rust library that provides structured, asynchronous logging and span-based observability. In addition to traditional logging macros (info!, error!, etc.), it supports distributed tracing and metrics collection, optimized for monitoring in microservices environments. In 2025, rapid adoption expansion is occurring in Rust development for microservices and cloud-native environments, gaining attention as a choice for full-scale production systems due to the increasing importance of structured logging and distributed tracing.

Details

The 2025 version of tracing is becoming a standard choice for modern Rust projects emphasizing observability. Beyond traditional log output functionality, it introduces the concept of "spans" to track application execution flows, powerfully supporting request tracking, performance analysis, and debugging in distributed systems. With high affinity for asynchronous processing and integration with the Tokio ecosystem, it is highly valued for use in high-performance asynchronous applications.

Key Features

• Structured Logging: Rich context information management in key-value format
• Span-based Tracing: Tracking from process start to completion with nested structures
• Asynchronous Support: Complete integration with asynchronous runtimes like Tokio
• Distributed Tracing: Distributed system visualization through OpenTelemetry integration
• Metrics Collection: Automatic collection and analysis of performance indicators
• Extensible Subscriber System: Pluggable output destinations and formats

Pros and Cons

Pros

• Excellent observability in microservices and cloud-native environments
• Minimal performance degradation through complete integration with asynchronous processing
• Industry-standard distributed tracing support through OpenTelemetry
• Easy machine analysis and querying through structured logs
• Complex processing flow visualization possible through span functionality
• Rich ecosystem and active community support

Cons

• Higher learning cost compared to traditional logging libraries
• Features may be excessive for simple applications
• Time required to understand configuration and Subscribers
• Tendency for higher memory usage than traditional logging libraries
• Complex debug output difficult for beginners to understand
• Introduction cost may not be justified for small-scale projects

Reference Pages

• tracing GitHub Repository
• tracing Rust Documentation
• Tracing Book

Usage Examples

Installation and Basic Setup

# Add dependencies to Cargo.toml
[dependencies]
tracing = "0.1"
tracing-subscriber = "0.3"

# Recommended setup for asynchronous applications
tokio = { version = "1.0", features = ["full"] }
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
tracing-opentelemetry = "0.21"  # For OpenTelemetry integration
tracing-appender = "0.2"        # For file output

Basic Logging (Compatible with Traditional log Crate)

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

fn main() {
    // Initialize basic Subscriber
    tracing_subscriber::init();

    // Usage similar to traditional logging libraries
    trace!("Trace level detailed information");
    debug!("Debug info: Application starting");
    info!("Info: Configuration file loaded");
    warn!("Warning: Using temporary configuration");
    error!("Error: Database connection failed");

    // Structured logging (key-value format)
    info!(
        user_id = 12345,
        action = "login",
        ip_address = "192.168.1.100",
        "User logged in"
    );

    // Variable expansion
    let request_id = "req_abcd1234";
    let response_time_ms = 150;
    
    info!(
        request_id,
        response_time_ms,
        "Request processing completed"
    );
}

Span-based Tracing

use tracing::{info, warn, error, span, Level, instrument};
use tracing_subscriber;

#[tokio::main]
async fn main() {
    tracing_subscriber::init();

    info!("Application starting");

    // Manual span creation
    let span = span!(Level::INFO, "user_registration", user_id = 12345);
    let _enter = span.enter();

    info!("User registration process started");
    
    // Nested span
    register_user("[email protected]").await;
    
    info!("User registration process completed");
}

// Automatic span generation (using instrument attribute)
#[instrument]
async fn register_user(email: &str) -> Result<u64, String> {
    info!("User registration started");
    
    // Database operation span
    let user_id = create_user_in_database(email).await?;
    
    // Email sending span
    send_welcome_email(email, user_id).await?;
    
    info!(user_id, "User registration completed successfully");
    Ok(user_id)
}

#[instrument(skip(email), fields(email = %email))]
async fn create_user_in_database(email: &str) -> Result<u64, String> {
    info!("Creating user in database");
    
    // Database operation simulation
    tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
    
    let user_id = 12345; // Generated user ID
    info!(user_id, "User created in database");
    
    Ok(user_id)
}

#[instrument]
async fn send_welcome_email(email: &str, user_id: u64) -> Result<(), String> {
    info!("Sending welcome email");
    
    // Email sending simulation
    tokio::time::sleep(tokio::time::Duration::from_millis(200)).await;
    
    info!("Welcome email sent successfully");
    Ok(())
}

Advanced Subscriber Configuration and Filtering

use tracing::{info, warn, error, Level};
use tracing_subscriber::{
    fmt,
    layer::SubscriberExt,
    util::SubscriberInitExt,
    EnvFilter,
    Registry,
};
use tracing_appender::{rolling, non_blocking};

fn main() {
    // Subscriber configuration with multiple output destinations
    let file_appender = rolling::daily("logs", "app.log");
    let (non_blocking, _guard) = non_blocking(file_appender);

    let subscriber = Registry::default()
        .with(EnvFilter::from_default_env()
            .add_directive("myapp=debug".parse().unwrap())
            .add_directive("myapp::database=trace".parse().unwrap()))
        .with(fmt::Layer::new()
            .with_writer(std::io::stdout)
            .with_ansi(true)
            .with_level(true)
            .with_target(true)
            .with_thread_ids(true)
            .with_thread_names(true))
        .with(fmt::Layer::new()
            .with_writer(non_blocking)
            .with_ansi(false)
            .json());

    subscriber.init();

    info!("Application started with configured Subscriber");

    // Logs from various modules
    database_operations();
    network_operations();
    business_logic();
}

mod database {
    use tracing::{info, debug, error, instrument, span, Level};

    #[instrument]
    pub fn connect() -> Result<(), &'static str> {
        debug!("Loading database connection configuration");
        info!("Connected to database");
        Ok(())
    }

    #[instrument(skip(query), fields(query_type = "SELECT"))]
    pub fn execute_query(query: &str) -> Result<Vec<String>, &'static str> {
        let span = span!(Level::DEBUG, "query_execution", query_length = query.len());
        let _enter = span.enter();
        
        debug!("Executing SQL query");
        
        // Query execution simulation
        std::thread::sleep(std::time::Duration::from_millis(50));
        
        info!(rows_affected = 3, "Query executed successfully");
        Ok(vec!["row1".to_string(), "row2".to_string(), "row3".to_string()])
    }
}

mod network {
    use tracing::{info, warn, error, instrument};

    #[instrument]
    pub fn send_http_request(url: &str) -> Result<String, &'static str> {
        info!("HTTP request sending started");
        
        // Network processing simulation
        std::thread::sleep(std::time::Duration::from_millis(300));
        
        info!(status_code = 200, "HTTP request successful");
        Ok("response_data".to_string())
    }

    #[instrument]
    pub fn handle_timeout() {
        warn!("Network timeout occurred");
        error!("Connection timed out");
    }
}

fn database_operations() {
    let _ = database::connect();
    let _ = database::execute_query("SELECT * FROM users WHERE active = true");
}

fn network_operations() {
    let _ = network::send_http_request("https://api.example.com/data");
    network::handle_timeout();
}

fn business_logic() {
    info!("Business logic processing started");
    info!("Business logic processing completed");
}

Asynchronous Processing and OpenTelemetry Integration

use tracing::{info, instrument, Span};
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
use tracing_opentelemetry::OpenTelemetryLayer;
use opentelemetry::{global, KeyValue};
use opentelemetry_sdk::{
    trace::{self, TracerProvider},
    Resource,
};
use opentelemetry_jaeger::JaegerPipeline;

#[tokio::main]
async fn main() -> Result<(), Box<dyn std::error::Error + Send + Sync + 'static>> {
    // OpenTelemetry tracer configuration
    global::set_text_map_propagator(opentelemetry_jaeger::Propagator::new());
    
    let tracer = opentelemetry_jaeger::new_agent_pipeline()
        .with_service_name("myapp")
        .install_simple()?;

    // Subscriber configuration
    tracing_subscriber::registry()
        .with(tracing_subscriber::EnvFilter::new("myapp=debug"))
        .with(tracing_subscriber::fmt::layer())
        .with(OpenTelemetryLayer::new(tracer))
        .init();

    info!("Distributed tracing enabled application started");

    // Distributed tracing enabled processing
    process_order("order_12345").await?;

    // OpenTelemetry shutdown
    global::shutdown_tracer_provider();
    Ok(())
}

#[instrument]
async fn process_order(order_id: &str) -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
    info!("Order processing started");
    
    // Add custom attributes
    Span::current().set_attribute(KeyValue::new("order.priority", "high"));
    
    // Process each step
    validate_order(order_id).await?;
    reserve_inventory(order_id).await?;
    process_payment(order_id).await?;
    ship_order(order_id).await?;
    
    info!("Order processing completed");
    Ok(())
}

#[instrument]
async fn validate_order(order_id: &str) -> Result<(), &'static str> {
    info!("Validating order");
    tokio::time::sleep(tokio::time::Duration::from_millis(50)).await;
    
    // Validation result
    Span::current().set_attribute(KeyValue::new("validation.result", "success"));
    info!("Order validation completed");
    Ok(())
}

#[instrument]
async fn reserve_inventory(order_id: &str) -> Result<(), &'static str> {
    info!("Reserving inventory");
    tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
    
    let reserved_items = 3;
    Span::current().set_attribute(KeyValue::new("inventory.reserved_items", reserved_items));
    info!(reserved_items, "Inventory reservation completed");
    Ok(())
}

#[instrument]
async fn process_payment(order_id: &str) -> Result<(), &'static str> {
    info!("Processing payment");
    tokio::time::sleep(tokio::time::Duration::from_millis(200)).await;
    
    let amount = 9999;
    Span::current().set_attribute(KeyValue::new("payment.amount", amount));
    Span::current().set_attribute(KeyValue::new("payment.method", "credit_card"));
    
    info!(amount, "Payment processing completed");
    Ok(())
}

#[instrument]
async fn ship_order(order_id: &str) -> Result<(), &'static str> {
    info!("Arranging shipment");
    tokio::time::sleep(tokio::time::Duration::from_millis(80)).await;
    
    let tracking_number = "TRK123456789";
    Span::current().set_attribute(KeyValue::new("shipping.tracking_number", tracking_number));
    
    info!(tracking_number, "Shipment arrangement completed");
    Ok(())
}

Custom Subscriber and Metrics Collection

use tracing::{info, warn, error, Subscriber, Event, Id, span};
use tracing_subscriber::{
    layer::{Context, SubscriberExt},
    Layer, Registry,
};
use std::collections::HashMap;
use std::sync::{Arc, Mutex};
use std::time::{Duration, Instant};

// Custom metrics collection Layer
#[derive(Debug, Clone)]
struct MetricsLayer {
    metrics: Arc<Mutex<Metrics>>,
}

#[derive(Debug, Default)]
struct Metrics {
    log_counts: HashMap<String, u64>,
    error_counts: HashMap<String, u64>,
    span_durations: HashMap<String, Vec<Duration>>,
}

impl MetricsLayer {
    fn new() -> Self {
        Self {
            metrics: Arc::new(Mutex::new(Metrics::default())),
        }
    }

    fn print_metrics(&self) {
        let metrics = self.metrics.lock().unwrap();
        
        println!("\n=== Metrics Report ===");
        
        println!("Log Counts:");
        for (level, count) in &metrics.log_counts {
            println!("  {}: {}", level, count);
        }
        
        println!("Error Counts:");
        for (target, count) in &metrics.error_counts {
            println!("  {}: {}", target, count);
        }
        
        println!("Span Execution Times (Average):");
        for (name, durations) in &metrics.span_durations {
            if !durations.is_empty() {
                let avg = durations.iter().sum::<Duration>() / durations.len() as u32;
                println!("  {}: {:?}", name, avg);
            }
        }
    }
}

impl<S> Layer<S> for MetricsLayer
where
    S: Subscriber,
{
    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
        let mut metrics = self.metrics.lock().unwrap();
        
        // Count by log level
        let level = event.metadata().level().to_string();
        *metrics.log_counts.entry(level.clone()).or_insert(0) += 1;
        
        // For error level, count by target
        if *event.metadata().level() == tracing::Level::ERROR {
            let target = event.metadata().target().to_string();
            *metrics.error_counts.entry(target).or_insert(0) += 1;
        }
    }

    fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
        // Record span start time
        if let Some(span) = ctx.span(id) {
            span.extensions_mut().insert(Instant::now());
        }
    }

    fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
        // Calculate span execution time
        if let Some(span) = ctx.span(id) {
            if let Some(start_time) = span.extensions().get::<Instant>() {
                let duration = start_time.elapsed();
                let span_name = span.name().to_string();
                
                let mut metrics = self.metrics.lock().unwrap();
                metrics.span_durations
                    .entry(span_name)
                    .or_insert_with(Vec::new)
                    .push(duration);
            }
        }
    }
}

#[tokio::main]
async fn main() {
    let metrics_layer = MetricsLayer::new();
    
    // Custom Subscriber configuration
    let subscriber = Registry::default()
        .with(tracing_subscriber::fmt::layer())
        .with(metrics_layer.clone());

    tracing::subscriber::set_global_default(subscriber)
        .expect("Failed to set subscriber");

    info!("Custom metrics collection started");

    // Execute various processes
    for i in 0..5 {
        process_request(i).await;
    }

    // Intentional error generation
    error!("Test error 1");
    error!("Test error 2");
    warn!("Warning message");

    // Display metrics
    metrics_layer.print_metrics();
}

#[tracing::instrument]
async fn process_request(request_id: usize) {
    info!(request_id, "Request processing started");
    
    // Random delay to create processing time variations
    let delay = 50 + (request_id * 25);
    tokio::time::sleep(tokio::time::Duration::from_millis(delay as u64)).await;
    
    if request_id % 3 == 0 {
        error!("Request processing error");
    } else {
        info!(request_id, "Request processing completed");
    }
}

Practical Web Application Integration Example

use tracing::{info, warn, error, instrument, Span};
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
use uuid::Uuid;
use std::collections::HashMap;

// Request ID generation and context management
#[derive(Debug, Clone)]
struct RequestContext {
    request_id: String,
    user_id: Option<u64>,
    ip_address: String,
}

impl RequestContext {
    fn new(user_id: Option<u64>, ip_address: String) -> Self {
        Self {
            request_id: Uuid::new_v4().to_string(),
            user_id,
            ip_address,
        }
    }

    fn attach_to_span(&self) {
        let span = Span::current();
        span.record("request_id", &self.request_id);
        span.record("user_id", &self.user_id.unwrap_or(0));
        span.record("ip_address", &self.ip_address);
    }
}

#[tokio::main]
async fn main() {
    // Full-featured Subscriber configuration for web applications
    tracing_subscriber::registry()
        .with(
            tracing_subscriber::EnvFilter::try_from_default_env()
                .unwrap_or_else(|_| "myapp=debug,tower_http=debug".into()),
        )
        .with(tracing_subscriber::fmt::layer()
            .with_target(false)
            .with_timer(tracing_subscriber::fmt::time::UtcTime::rfc_3339())
            .with_level(true))
        .init();

    info!("Web application started");

    // Simulate multiple request processing
    let requests = vec![
        (Some(12345), "192.168.1.100"),
        (None, "10.0.0.50"),
        (Some(67890), "203.0.113.25"),
    ];

    for (user_id, ip) in requests {
        let ctx = RequestContext::new(user_id, ip.to_string());
        handle_http_request(ctx).await;
    }
}

#[instrument(
    skip(ctx),
    fields(
        request_id = %ctx.request_id,
        user_id = ctx.user_id,
        ip_address = %ctx.ip_address
    )
)]
async fn handle_http_request(ctx: RequestContext) {
    info!("HTTP request received");
    
    // Request processing
    match process_business_logic(&ctx).await {
        Ok(result) => {
            info!(result = %result, "Request processing successful");
        }
        Err(e) => {
            error!(error = %e, "Request processing failed");
        }
    }
}

#[instrument(skip(ctx))]
async fn process_business_logic(ctx: &RequestContext) -> Result<String, &'static str> {
    ctx.attach_to_span();
    
    info!("Business logic processing started");
    
    // Authentication check
    if let Some(user_id) = ctx.user_id {
        authenticate_user(user_id).await?;
    } else {
        warn!("Request from unauthenticated user");
    }
    
    // Data processing
    let data = fetch_data().await?;
    let processed_data = transform_data(data).await?;
    
    info!("Business logic processing completed");
    Ok(processed_data)
}

#[instrument]
async fn authenticate_user(user_id: u64) -> Result<(), &'static str> {
    info!("User authentication started");
    
    // Authentication processing simulation
    tokio::time::sleep(tokio::time::Duration::from_millis(30)).await;
    
    // Record user information
    Span::current().record("user_role", "premium");
    
    info!("User authentication successful");
    Ok(())
}

#[instrument]
async fn fetch_data() -> Result<HashMap<String, String>, &'static str> {
    info!("Data fetching started");
    
    // Database query simulation
    tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
    
    let mut data = HashMap::new();
    data.insert("key1".to_string(), "value1".to_string());
    data.insert("key2".to_string(), "value2".to_string());
    
    info!(records_count = data.len(), "Data fetching completed");
    Ok(data)
}

#[instrument(skip(data))]
async fn transform_data(data: HashMap<String, String>) -> Result<String, &'static str> {
    info!(input_size = data.len(), "Data transformation started");
    
    // Data transformation processing simulation
    tokio::time::sleep(tokio::time::Duration::from_millis(50)).await;
    
    let result = serde_json::to_string(&data).unwrap_or_else(|_| "{}".to_string());
    
    info!(output_size = result.len(), "Data transformation completed");
    Ok(result)
}