When flat logs fail
You are debugging a web server that handles concurrent requests. You added log::info!("received request") at the top of your handler and log::info!("sending response") at the bottom. The logs print out. You see a stream of messages. Then a bug appears: one request hangs, and the server stops responding. You grep the logs for the request ID. You find "received request" and then "sending response" for a different request. The logs are interleaved. You cannot tell which log line belongs to which user. The flat list of events has lost the structure of your execution.
This is the core problem log cannot solve. log records discrete events. It gives you a diary of what happened. It does not track the flow of control. When you have async tasks, recursive calls, or concurrent workers, a flat list becomes noise. You need to see the tree. You need to know which operation started, which operation it called, and where time was spent. That is what tracing provides.
The data model: events versus spans
Both log and tracing are facades. They define the API you use to emit data, but they do not print anything by themselves. You must install a backend to capture and display the output. log needs a logger like env_logger. tracing needs a subscriber like tracing-subscriber. The difference lies in the data model each facade supports.
log has one primitive: the event. An event is a point in time with a level, a message, and optional key-value fields. It is a leaf node. There is no concept of nesting or duration.
tracing has two primitives: events and spans. An event is the same as in log. A span represents a period of time. You create a span, enter it, do work, and exit it. Spans can nest inside other spans. When an event fires, it attaches to the set of currently active spans. This creates a hierarchical structure. The subscriber receives a tree of spans with events attached at specific points. You can calculate latency, visualize call stacks, and correlate events across async boundaries.
Think of log as a grocery receipt. It lists items you bought in the order you scanned them. Think of tracing as a receipt with categories, subtotals, and timestamps for when you picked up each item. One tells you what happened. The other tells you how it happened and how long it took.
Minimal example: seeing the difference
Here is how the code looks side by side. The log example produces a flat stream. The tracing example produces a structured hierarchy.
use log::info;
/// Demonstrates flat logging with no nesting context.
fn main() {
// Initialize a logger. Without this, log::info does nothing.
env_logger::init();
info!("Starting application");
process_request(1);
process_request(2);
info!("Application finished");
}
fn process_request(id: u32) {
// These events are indistinguishable from the top-level events.
// There is no way to group them by request.
info!("Processing request {}", id);
do_heavy_work();
info!("Finished request {}", id);
}
fn do_heavy_work() {
info!("Doing heavy work");
}
The output is a flat list. If process_request is called concurrently, the logs interleave. You lose the grouping.
Here is the same logic rewritten with tracing. The span guards establish parent-child relationships automatically.
use tracing::{info, span, Level};
/// Demonstrates structured tracing with nested spans.
fn main() {
// Initialize the subscriber. This formats output and tracks spans.
tracing_subscriber::fmt::init();
// Create a root span for the application lifecycle.
let _app_span = span!(Level::INFO, "app").entered();
info!("Starting application");
process_request(1);
process_request(2);
info!("Application finished");
}
fn process_request(id: u32) {
// Create a span for this request. It nests inside the "app" span.
// The span carries the request ID as structured data.
let _req_span = span!(Level::INFO, "request", id = id).entered();
info!("Processing request");
do_heavy_work();
info!("Finished request");
}
fn do_heavy_work() {
// This span nests inside the "request" span.
// The hierarchy is preserved automatically.
let _work_span = span!(Level::INFO, "heavy_work").entered();
info!("Doing heavy work");
}
The output shows indentation or brackets that indicate nesting. Events are associated with their parent spans. You can see that "heavy_work" belongs to "request", which belongs to "app". The structure survives concurrency.
Trust the hierarchy. Once you see the spans, you stop guessing which log line belongs to which operation.
How the subscriber connects the dots
The subscriber is the engine behind tracing. It listens for spans and events, filters them based on configuration, and formats them for output. The default tracing-subscriber::fmt layer prints to stdout with colors and indentation. It tracks the active span stack in thread-local storage.
When you call span.enter(), the subscriber pushes the span onto the stack. When the guard drops, it pops the span. When you call info!, the subscriber looks at the current stack and attaches the event to all active spans. This mechanism allows the subscriber to reconstruct the full context at runtime.
The subscriber also handles filtering. You can configure it to only show spans above a certain level, or only for specific modules. This is controlled via the RUST_LOG environment variable. Both env_logger and tracing-subscriber use the same RUST_LOG syntax. This is a community convention that makes switching between tools easier. Set RUST_LOG=info and both tools respect it.
Convention aside: tracing_subscriber::fmt::init() is the quick start for development. In production, you configure the subscriber with layers for JSON output, file rotation, or remote export. The community standard is to build the subscriber once at startup and let it run. Do not create subscribers per request.
Build the subscriber once at main. Let it handle the rest.
Realistic scenario: async context propagation
The killer feature of tracing is context propagation across async boundaries. In an async application, tasks yield and resume. The call stack is not preserved. If you use log, you must manually pass context through every await point. This is error-prone and verbose.
tracing captures the current span context and attaches it to spawned tasks. The subscriber restores the context when the task resumes. This works automatically if you use the right patterns.
Here is how async context survives a task spawn. The .in_current_span() method captures the active span set and binds it to the new task.
use tracing::{info, span, Level};
/// Demonstrates span propagation across async tasks.
#[tokio::main]
async fn main() {
tracing_subscriber::fmt::init();
let span = span!(Level::INFO, "request", id = 42);
let _guard = span.enter();
info!("Received request");
// Spawn a background task.
// Without care, the new task loses the span context.
// Use in_current_span() to capture the active span.
let handle = tokio::spawn(async {
// This event is now associated with the "request" span.
// The subscriber knows this task belongs to request 42.
info!("Processing async work");
"done"
}).in_current_span();
let result = handle.await.unwrap();
info!("Request finished with {}", result);
}
The .in_current_span() call captures the current span set and attaches it to the task. When the task runs, the subscriber restores the spans. Events inside the task appear nested under the request span. If you forget .in_current_span(), the task runs with no context. The events float at the top level. You lose the correlation.
Don't fight async context. Let spans carry the data for you. Manual context passing is a maintenance trap.
Pitfalls and silent failures
tracing has a few traps that catch new users. The most common is the silent drop. If you forget to initialize a subscriber, tracing discards all events. Your code runs, but you see nothing. The macros are not broken. The subscriber is missing. Always call tracing_subscriber::fmt::init() or build a subscriber before emitting events.
Performance is another consideration. tracing has more overhead than log because it tracks span state and structured data. In tight loops, this overhead can matter. The macros check a global filter before executing the body. If the level is disabled, the cost is minimal. However, creating spans and recording fields has a cost. Profile your application. If logging is the bottleneck, reduce the verbosity or switch to log for hot paths.
Structured data requires discipline. tracing encourages key-value fields. If you dump raw strings into fields, you lose the benefit of structured logging. Use typed fields when possible. The subscriber can serialize them to JSON or other formats. This makes downstream analysis easier.
Convention aside: Use #[instrument] from tracing-attributes for functions. It automatically creates a span, enters it, and exits it when the function returns. It captures arguments as fields. This reduces boilerplate and ensures consistency. The community considers #[instrument] the standard way to instrument functions.
Here is how the macro replaces manual span guards. The compiler expands it into the exact same enter/exit logic you wrote earlier.
use tracing::info;
/// Instruments the function automatically with a span.
/// The span name is "process". Arguments are captured as fields.
#[tracing::instrument(level = "info", fields(user_id))]
fn process(user_id: u32) {
info!("Processing user");
// Span exits automatically when the function returns.
}
The #[instrument] macro generates the span code for you. It handles the guard and the fields. It is safer and less verbose than manual spans. Use it everywhere you can.
If your logs are empty, check the subscriber. The code is fine; the listener is missing.
Decision: log versus tracing
Choosing between log and tracing depends on your application's complexity and your observability needs. Both are valid tools. The ecosystem supports both. The decision comes down to structure and async support.
Use log when you need a lightweight dependency and only care about discrete events like "started", "stopped", or "error occurred".
Use log when you are writing a simple CLI tool or a library that does not require structured context or latency tracking.
Use log when you are maintaining a legacy codebase that already uses log and you do not want to migrate the entire codebase at once.
Use tracing when you are building an async application and need to track execution across task boundaries and await points.
Use tracing when you need structured data to feed into observability backends like Jaeger, Zipkin, Datadog, or Grafana Loki.
Use tracing when you want to measure the latency of specific operations using spans and need to visualize the call hierarchy.
Use tracing-log when you have a codebase using log but want to capture those events in tracing without rewriting the logging calls. This crate bridges the two facades.
Reach for log for simplicity. Reach for tracing for structure. Pick the tool that matches your complexity. Simple scripts get log. Distributed systems get tracing.