Edmondo's Vault

Logging in Rust

May 18, 20265 min read

log

log is not a logging library in itself but an interface or facade for logging. It defines logging macros such as error!, warn!, info!, debug!, and trace!. These macros are used by libraries and applications to produce logs, but log does not handle how these logs are output or managed. Instead, it delegates this responsibility to a backend implementation, such as env_logger or slog.

The separation of the interface (log) from the backend allows libraries to remain agnostic to the specific logging implementation used by the application.

env_logger

env_logger is a simple backend implementation for the log interface. It writes logs to stderr and provides runtime configuration via the RUST_LOG environment variable. This makes it easy to dynamically adjust log levels without modifying or recompiling your code. It’s suitable for smaller or simpler projects.

Example of combining log with env_logger:

use log::{info, warn};
use env_logger;
 
fn main() {
    env_logger::init(); // Initialize the logger backend
    info!("Application started");
    warn!("This is a warning message");
}

slog

slog (Structured Logger) is another backend implementation, but it focuses on structured logging, allowing logs to carry rich metadata in addition to simple text messages. This makes it ideal for applications that require structured data for log analysis, but it may be more complex than env_logger for simple projects.

tracing

tracing is a separate logging framework developed by the Tokio project. It is not compatible with the log interface and uses its own API. In addition to structured logging, tracing introduces the concept of spans, which are essential for asynchronous applications.

Spans

Spans represent a period of time in your program’s execution and allow you to track the flow of execution across asynchronous tasks. tracing also provides automatic instrumentation for functions using the #[instrument] attribute.

Span Example:

use tracing::{info, span, Level};
use tracing_subscriber;
 
#[tokio::main]
async fn main() {
    tracing_subscriber::fmt::init(); // Initialize tracing
 
    let parent_span = span!(Level::INFO, "parent_span");
    let _enter = parent_span.enter(); // Enter the parent span
 
    async_task().await;
}
 
async fn async_task() {
    let span = span!(Level::DEBUG, "async_task", task_id = 1);
    let _enter = span.enter(); // Enter a nested span
 
    info!("Performing async work");
}

Here, the log message “Performing async work” is associated with both the async_task span and its parent span, making it easier to trace the program’s flow. With #[instrument], tracing can automatically generate spans for functions and capture their arguments as structured metadata.

use tracing::{info, instrument};
use tracing_subscriber;
 
#[tokio::main]
async fn main() {
    tracing_subscriber::fmt::init();
 
    do_work("example").await;
}
 
#[instrument]
async fn do_work(task_name: &str) {
    info!("Starting work");
}

tracing supports structured logging by allowing you to attach key-value pairs to log messages and spans. This makes logs easier to analyze programmatically.

use tracing::{info, span, Level};
 
fn main() {
    let my_span = span!(Level::INFO, "example_span", user_id = 42, action = "login");
    let _enter = my_span.enter();
 
    info!("User performed an action");
}

Tracing layers and subscribers

The tracing-subscriber crate provides powerful mechanisms to manage and customize the behavior of spans and events in Rust applications. The core concept revolves around layers and subscribers. While subscribers are responsible for managing and collecting spans and events, layers add modular functionality on top of subscribers.

When you use the init() method on a layer (e.g., console_subscriber::ConsoleLayer::init()), the layer is set as the global subscriber. This effectively registers the layer to receive and process all spans and events in your application. Internally this happens:

  1. Wraps itself in a subscriber (Registry by default).
  2. Registers the subscriber globally using tracing::subscriber::set_global_default.
use console_subscriber::ConsoleLayer;
 
ConsoleLayer::builder()
    .retention(std::time::Duration::from_secs(60))
    .init();

The registry approach allows you to compose multiple layers into a single subscriber. Instead of a single layer owning the global subscriber, the Registry serves as the subscriber, and layers are added to it to extend its functionality.

use tracing_subscriber::{fmt, EnvFilter, Registry};
use tracing_subscriber::prelude::*;
 
let console_layer = console_subscriber::spawn();
let fmt_layer = fmt::layer();
let filter_layer = EnvFilter::new("debug");
 
tracing_subscriber::registry()
    .with(console_layer)
    .with(fmt_layer)
    .with(filter_layer)
    .init();

Common Layer Options in tracing-subscriber

FmtLayer

The FmtLayer provides human-readable output for spans and events. It supports customizable formats, including JSON. This layer is commonly used for basic logging.

use tracing_subscriber::fmt;
 
tracing_subscriber::fmt()
    .with_thread_ids(true) // Include thread IDs
    .with_thread_names(true) // Include thread names
    .json() // Output logs in JSON format
    .init();

EnvFilter

The EnvFilter layer enables runtime control over log verbosity based on environment variables. This is especially useful for dynamic filtering without recompiling your application.

use tracing_subscriber::EnvFilter;
 
let filter_layer = EnvFilter::new("info,my_crate=debug");
tracing_subscriber::fmt()
    .with_env_filter(filter_layer)
    .init();
  • info,my_crate=debug means:
    • Logs at info level for all crates.
    • Logs at debug level for my_crate.
RUST_LOG=info,my_crate=debug cargo run

ConsoleLayer

Part of the console-subscriber crate, this layer provides a live debugging console for asynchronous tasks in Tokio-based applications. It tracks tasks, resources, and spans in real-time.

Example:

use console_subscriber::ConsoleLayer;
 
let console_layer = ConsoleLayer::builder()
    .retention(std::time::Duration::from_secs(60))
    .server_addr(([127, 0, 0, 1], 5555))
    .spawn();
 
tracing_subscriber::registry()
    .with(console_layer)
    .init();

OpentelemetryLayer

The OpentelemetryLayer exports tracing data to observability platforms like Jaeger or Zipkin for distributed tracing. It integrates with the opentelemetry crate.

use tracing_opentelemetry::OpenTelemetryLayer;
use tracing_subscriber::{Registry, prelude::*};
use opentelemetry::sdk::export::trace::stdout;
 
let tracer = stdout::new_pipeline().install_simple();
let telemetry_layer = OpenTelemetryLayer::new(tracer);
 
tracing_subscriber::registry()
    .with(telemetry_layer)
    .init();

FilterLayer

The FilterLayer allows you to dynamically control which spans and events are recorded. It can filter based on span names, metadata, or other criteria.

use tracing_subscriber::filter::{filter_fn, LevelFilter};
use tracing_subscriber::fmt;
 
let filter_layer = filter_fn(|metadata| metadata.level() <= &tracing::Level::INFO);
 
tracing_subscriber::fmt()
    .with_filter(filter_layer)
    .init();

Graph View

Backlinks

  • No backlinks found