When logs become a black box
You've built an Axum server. It works locally. You deploy it. Suddenly, a request hangs. Or returns a 500. You check the logs. Nothing. Or worse, a wall of println! statements that tell you nothing about which request failed. You see "Database error" but you don't know if it was the login request or the profile update. You don't know the user ID. You don't know the request path. You're guessing.
Adding more println! calls makes it worse. The logs become a flat stream of text. You can't correlate events. You can't filter by request. You can't see the flow of execution through async tasks. You need a system that tracks context. You need to know that request ID 42 failed because the database timed out, not because the router broke.
That's what tracing is for. It gives you structured, hierarchical logs that follow your code through async boundaries. It lets you filter noise. It lets you trace a single request from the HTTP handler down to the database query and back.
Spans, events, and subscribers
tracing provides two primitives: spans and events.
A span is a period of time. It has a start and an end. You enter a span when a unit of work begins. You exit when it finishes. Spans nest. When you are inside a span, any event you fire is automatically associated with that span. This creates a tree of execution. A span can have fields. Fields are key-value pairs that describe the context. A request span might have fields for method, uri, and request_id.
An event is a point-in-time message. It has a level, like info, debug, or error. It can also have fields. An event might say "Database query took 50ms" with a field for duration. Events are attached to the current span. If you fire an event inside a request span, the log output shows that the event happened during that request.
A subscriber listens to spans and events. It decides what to do with them. The default subscriber prints them to stdout. Other subscribers can send them to a file, a log aggregator, or a distributed tracing backend. Subscribers can also filter. You can configure a subscriber to only show info and above in production, but show debug in development.
Logs without context are just noise. Structure saves you.
Minimal setup
Start with the dependencies. You need tracing for the macros and tracing-subscriber to capture the output.
[dependencies]
axum = "0.7"
tokio = { version = "1", features = ["full"] }
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
The env-filter feature is standard. It lets you control log levels via the RUST_LOG environment variable.
Here is a minimal server with tracing enabled.
use axum::{routing::get, Router};
use tracing_subscriber::EnvFilter;
#[tokio::main]
async fn main() {
// Initialize the subscriber with environment variable support.
// RUST_LOG=debug shows debug traces. RUST_LOG=info shows only info+.
// If RUST_LOG is not set, this defaults to "info".
tracing_subscriber::fmt()
.with_env_filter(EnvFilter::from_default_env())
.init();
let app = Router::new().route("/hello", get(hello));
// Start the server.
axum::serve(
tokio::net::TcpListener::bind("0.0.0.0:3000").await.unwrap(),
app.into_make_service(),
)
.await
.unwrap();
}
/// Handle the hello route with automatic tracing instrumentation.
#[tracing::instrument]
async fn hello() -> &'static str {
// This event is automatically nested inside the span created by #[instrument].
tracing::info!("Handling hello request");
"Hello, world!"
}
Run this with RUST_LOG=info. You'll see output like:
INFO axum_app::hello: Handling hello request
The axum_app::hello part is the span context. It tells you the event happened inside the hello function. The #[tracing::instrument] macro created that span automatically. It used the function name as the span name. It started the span when the function was called. It ended the span when the function returned.
Run it with RUST_LOG=debug and add a tracing::debug! call inside the handler. You'll see the debug line appear. Change back to info and it disappears. The subscriber filtered it out.
Run it. Watch the hierarchy. The span wraps the event.
Realistic request tracing
Real applications need more than function names. You want request IDs. You want to log the method and path. You want to track the response status. You want to correlate logs across multiple services.
Middleware is the right place to inject request-level context. You can create a span for each request and add fields to it. All handlers and child spans will inherit those fields.
use axum::{
extract::Request,
middleware::Next,
response::Response,
routing::get,
Router,
};
use uuid::Uuid;
use tracing::Span;
use tracing_subscriber::EnvFilter;
/// Middleware to attach a unique request ID to the tracing span.
async fn trace_request_id(mut req: Request, next: Next) -> Response {
// Generate a unique ID for this request.
let id = Uuid::new_v4();
// Extend the current span with the request ID field.
// This makes the ID available to all child spans and events.
Span::current().record("request_id", &id.to_string());
// Log the incoming request details.
// The % syntax tells tracing to use Display formatting.
tracing::info!(
method = %req.method(),
uri = %req.uri(),
"Request started"
);
// Call the rest of the middleware chain and handlers.
let response = next.run(req).await;
// Log the response status.
tracing::info!(
status = response.status().as_u16(),
"Request finished"
);
response
}
#[tokio::main]
async fn main() {
// Initialize subscriber.
tracing_subscriber::fmt()
.with_env_filter(EnvFilter::from_default_env())
.init();
let app = Router::new()
.route("/users", get(list_users))
.layer(axum::middleware::from_fn(trace_request_id));
axum::serve(
tokio::net::TcpListener::bind("0.0.0.0:3000").await.unwrap(),
app.into_make_service(),
)
.await
.unwrap();
}
/// List users with a simulated delay.
#[tracing::instrument]
async fn list_users() -> &'static str {
// Simulate work.
tracing::debug!("Fetching users from database");
tokio::time::sleep(std::time::Duration::from_millis(50)).await;
"User list"
}
Now every log line includes the request_id. If you grep for that ID, you get every event related to that request. You see the request start, the database fetch, and the request finish. You can trace the full lifecycle.
The Span::current().record() call is key. It modifies the active span. Since the middleware runs before the handler, the span exists when the handler runs. The handler inherits the request_id field. Any tracing::info! inside the handler will include the ID.
Convention aside: The community standard is to use EnvFilter::from_default_env(). It respects RUST_LOG. You can set RUST_LOG=info,my_crate=debug to enable debug logging for your crate while keeping dependencies at info. This gives you fine-grained control without code changes.
Inject the ID early. Every log line becomes traceable.
Pitfalls and compiler errors
Tracing is powerful, but async code introduces traps.
Async task spawning breaks context.
If you spawn a background task, the new task starts in a fresh context. It does not inherit the parent span. You must attach the span explicitly.
// BAD: Span context is lost.
// The log line will not show the parent span.
tokio::spawn(async {
tracing::info!("This won't show the parent span");
});
// GOOD: Attach the current span to the task.
// The log line inherits the parent span context.
tokio::spawn(
async {
tracing::info!("This inherits the parent span");
}
.in_current_span(), // <-- Crucial for async context
);
If you forget .in_current_span(), the log output will look like the event happened outside any span. You lose the correlation. This is the most common mistake in async tracing.
Instrument macro requires Display or Debug.
The #[tracing::instrument] macro tries to record your function arguments as span fields. If an argument doesn't implement Display or Debug, the compiler rejects you with E0277 (trait bound not satisfied).
// BAD: MyStruct doesn't implement Display or Debug.
// Compiler error: E0277 trait bound not satisfied.
#[tracing::instrument]
async fn process(data: MyStruct) {
// ...
}
// GOOD: Skip the argument.
// The span is created, but data is not recorded as a field.
#[tracing::instrument(skip(data))]
async fn process(data: MyStruct) {
// ...
}
Use skip for arguments you don't want to log. Use skip_all to skip all arguments. Use fields(...) to add custom fields.
Subscriber initialization order matters.
The subscriber must be initialized before any traces are fired. If you fire a trace before calling init(), the trace is dropped. This usually happens if you have logging in static initializers or early startup code. Initialize the subscriber as the first line in main.
Spawn a task without in_current_span() and you lose the thread. Don't lose the thread.
When to use what
Use tracing when you need structured, hierarchical logs in an async application. Use tracing when you want to filter logs by level or target. Use tracing when you need to correlate events across async boundaries.
Use println! only for quick debugging scripts that you will delete before shipping. Never use println! in production code. It blocks on stdout. It provides no structure. It cannot be filtered.
Use log crate if you are maintaining a legacy codebase that already depends on it. The log crate is the older standard. tracing is the modern standard. New projects should use tracing. You can bridge log to tracing with tracing-log if you need to support both.
Use tracing-opentelemetry when you need to export traces to a distributed tracing backend like Jaeger or Zipkin. This lets you visualize request flows across multiple services.
Use #[tracing::instrument] on handlers and key functions to automatically create spans. It reduces boilerplate. It ensures spans are entered and exited correctly.
Use tracing::info!, tracing::debug!, tracing::error! for point-in-time events inside spans. Use info for important state changes. Use debug for detailed diagnostics. Use error for failures.
Use Span::current().record() in middleware to inject dynamic fields like request IDs. Use #[instrument(fields(...))] to declare static fields known at compile time.
Pick the tool that matches your observability needs. tracing scales with you.