Loading pageâŚ
Rust walkthroughs
Loading pageâŚ
tracing::Instrument::instrument attach span context to futures for distributed tracing?instrument wraps a future with a tracing span that is automatically entered when the future is polled and exited when the poll completes. This ensures that any events or child spans created during the future's execution are properly associated with the parent span in the trace hierarchy. The span contextâincluding trace ID, span ID, and parent referencesâis stored in thread-local storage during the poll, allowing downstream code to access the current trace context without explicit parameter passing. For distributed tracing, this means the trace context established at a service boundary propagates automatically through all async operations spawned from that request, creating a causal chain that spans across await points and even service boundaries when combined with context propagation headers.
use tracing::{info, instrument, span, Level};
use tracing::Instrument;
use std::time::Duration;
#[tokio::main]
async fn main() {
// Initialize a subscriber to see output
tracing_subscriber::fmt().init();
// Create a span manually
let span = span!(Level::INFO, "request_processing");
// instrument() wraps the future with the span
async fn process_request() {
info!("Processing request");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Request complete");
}
// Without instrument: events have no parent span
process_request().await;
// With instrument: events are children of the span
process_request().instrument(span).await;
}instrument() wraps a future so the span is entered during each poll.
use tracing::{info, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt().init();
// instrument() is a method from the Instrument trait
// It returns an Instrumented<F> wrapper
let span = span!(Level::INFO, "operation");
async fn my_async_work() -> i32 {
info!("Working...");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Done working");
42
}
// Method 1: Call .instrument() on the future
let result = my_async_work().instrument(span).await;
println!("Result: {}", result);
// Method 2: Use instrument() as a free function
let span = span!(Level::INFO, "another_operation");
let result = tracing::instrument(my_async_work(), span).await;
println!("Result: {}", result);
// The Instrumented wrapper:
// - Enters the span before each poll
// - Exits the span after each poll
// - Ensures proper context propagation across await points
}instrument() returns an Instrumented<F> wrapper that manages span lifecycle during polls.
use tracing::{info, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::DEBUG)
.init();
let span = span!(Level::INFO, "parent_span");
async fn multi_stage_work() {
info!("Stage 1: Starting");
// First await point
tokio::time::sleep(Duration::from_millis(5)).await;
// After first await, span is re-entered automatically
info!("Stage 2: After first sleep");
// Second await point
tokio::time::sleep(Duration::from_millis(5)).await;
// After second await, span is still active
info!("Stage 3: Complete");
}
// Without instrument: each event has no parent
println!("Without instrument:");
multi_stage_work().await;
// With instrument: all events are children of parent_span
println!("\nWith instrument:");
multi_stage_work().instrument(span).await;
}The span is entered before each poll and exited after, maintaining context across all await points.
use tracing::{info, instrument, Level};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt().init();
// The #[instrument] attribute automatically creates and attaches a span
process_order(123, "premium").await;
}
// #[instrument] creates a span named "process_order"
// It automatically logs function arguments
#[instrument]
async fn process_order(order_id: u32, tier: &str) {
info!("Validating order");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Processing payment");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Order complete");
}
// Can customize the span name and level
#[instrument(name = "user_authentication", level = Level::DEBUG)]
async fn authenticate_user(username: &str) -> bool {
info!("Checking credentials");
tokio::time::sleep(Duration::from_millis(5)).await;
username == "admin"
}
// Skip certain arguments from the span
#[instrument(skip(password))]
async fn login(username: &str, password: &str) -> bool {
info!("Attempting login");
authenticate_user(username).await
}
// Add custom fields to the span
#[instrument(fields(category = "api", version = "1.0"))]
async fn api_call(endpoint: &str) {
info!("Calling endpoint: {}", endpoint);
}#[instrument] is a convenient macro that generates the span and instrument wrapper automatically.
use tracing::{info, instrument, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_target(false)
.init();
// Parent span
let parent = span!(Level::INFO, "http_request", method = "GET", path = "/api/users");
async fn handle_request() {
info!("Starting request handling");
fetch_from_database().await;
call_external_service().await;
info!("Request complete");
}
async fn fetch_from_database() {
// This creates a child span of the current span
let span = span!(Level::INFO, "database_query", table = "users");
async {
info!("Executing query");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Query complete");
}
.instrument(span)
.await;
}
async fn call_external_service() {
let span = span!(Level::INFO, "external_call", service = "payment");
async {
info!("Calling external service");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("External call complete");
}
.instrument(span)
.await;
}
handle_request().instrument(parent).await;
}Child spans automatically become children of the currently active span, creating a hierarchy.
use tracing::{info, span, Level, Instrument};
use tracing_opentelemetry::OpenTelemetrySpanExt;
use opentelemetry::trace::{TraceContextExt, SpanKind};
#[tokio::main]
async fn main() {
// Set up OpenTelemetry exporter for distributed tracing
// (simplified - in production you'd configure a real exporter)
// When a request comes in with trace context headers:
// - traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
// - tracestate: some=value
// Extract the context and create a parent span
async fn handle_incoming_request(traceparent: Option<&str>) {
let span = if let Some(parent) = traceparent {
// Parse the traceparent and create a span with the extracted context
span!(Level::INFO, "incoming_request")
} else {
// Start a new trace
span!(Level::INFO, "incoming_request")
};
async {
info!("Processing incoming request");
call_downstream_service().await;
info!("Request processed");
}
.instrument(span)
.await;
}
async fn call_downstream_service() {
let span = span!(Level::INFO, "downstream_call", service = "inventory");
async {
info!("Calling inventory service");
// In a real implementation, you would:
// 1. Get the current span context
// 2. Inject it into HTTP headers
// 3. The downstream service extracts and continues the trace
tokio::time::sleep(std::time::Duration::from_millis(10)).await;
info!("Downstream call complete");
}
.instrument(span)
.await;
}
handle_incoming_request(None).await;
}Distributed tracing propagates trace context across service boundaries using the active span.
use tracing::{info, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::DEBUG)
.init();
let parent_span = span!(Level::INFO, "parent");
async fn demonstrate_context() {
// The current span is available via span!() and info!() etc.
// It's stored in thread-local storage during the poll
// Create a child span - it automatically becomes a child
let child_span = span!(Level::INFO, "child");
async {
info!("In child span");
// Grandchild is automatically a child of child
let grandchild = span!(Level::DEBUG, "grandchild");
async {
info!("In grandchild span");
}
.instrument(grandchild)
.await;
info!("Back in child span");
}
.instrument(child_span)
.await;
info!("Back in parent span");
}
// The instrument wrapper:
// 1. Before poll: enters the span (sets current span in thread-local)
// 2. During poll: all span!() and info!() use the current span
// 3. After poll: exits the span (restores parent span)
demonstrate_context().instrument(parent_span).await;
}The span context is stored in thread-local storage during each poll, making it available to all macros.
use tracing::{info, span, Level, Instrument};
use tokio::task::JoinHandle;
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt().init();
let parent_span = span!(Level::INFO, "main_operation");
// Without instrument: spawned task loses context
let handle1 = tokio::spawn(async {
info!("Task without instrument - no parent span!");
});
// With instrument: spawned task carries span context
let child_span = span!(Level::INFO, "background_task", task_id = 1);
let handle2: JoinHandle<()> = tokio::spawn(
async {
info!("Task with instrument - has parent span");
// Nested spans work too
let inner = span!(Level::DEBUG, "inner_work");
async {
info!("Inner work in spawned task");
}
.instrument(inner)
.await;
}
.instrument(child_span)
);
// Alternative: instrument within the spawn
let handle3 = tokio::spawn(
async {
info!("Another instrumented task");
}
.instrument(span!(Level::INFO, "task_3"))
);
// Wait for all tasks
handle1.await.unwrap();
handle2.await.unwrap();
handle3.await.unwrap();
// IMPORTANT: instrument() must be called INSIDE the spawn
// If called outside, the span may be entered before spawning
// and the context might not propagate correctly
}When spawning tasks, wrap the future with instrument() before spawning to carry span context.
use tracing::{info, instrument, span, Level, Instrument};
use std::time::Duration;
use std::sync::Arc;
use tokio::sync::Mutex;
// Simulated request context
struct RequestContext {
request_id: String,
user_id: Option<String>,
}
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::DEBUG)
.init();
// Each request gets its own span with request-scoped data
handle_request("req-123", Some("user-456")).await;
handle_request("req-789", None).await;
}
#[instrument(
name = "http_request",
skip(request_id, user_id),
fields(
request_id = %request_id,
user_id = ?user_id
)
)]
async fn handle_request(request_id: &str, user_id: Option<&str>) {
info!("Handling request");
// All child spans and events have the request_id field
authenticate(user_id).await;
process_data().await;
info!("Request complete");
}
#[instrument(skip(user_id))]
async fn authenticate(user_id: Option<&str>) {
match user_id {
Some(id) => {
info!(user_id = %id, "User authenticated");
}
None => {
info!("Anonymous request");
}
}
tokio::time::sleep(Duration::from_millis(5)).await;
}
#[instrument]
async fn process_data() {
info!("Processing data");
// Simulate parallel work with shared span context
let task1 = tokio::spawn(
async {
info!("Parallel task 1");
}
.instrument(span!(Level::DEBUG, "parallel_task_1"))
);
let task2 = tokio::spawn(
async {
info!("Parallel task 2");
}
.instrument(span!(Level::DEBUG, "parallel_task_2"))
);
task1.await.unwrap();
task2.await.unwrap();
info!("Data processing complete");
}Create request-scoped spans at service entry points to propagate context through all operations.
use tracing::{info, span, Level, Instrument};
use tracing_opentelemetry::OpenTelemetrySpanExt;
#[tokio::main]
async fn main() {
// Set up with OpenTelemetry for trace/span ID access
let tracer = opentelemetry_otlp::new_pipeline()
.tracing()
.with_exporter(opentelemetry_otlp::new_exporter().tonic())
.install_simple()
.unwrap();
let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);
tracing_subscriber::registry()
.with(telemetry)
.with(tracing_subscriber::fmt::layer())
.init();
let root_span = span!(Level::INFO, "root_operation");
async fn work_with_trace_ids() {
// Access the current span
let current_span = tracing::Span::current();
// Get trace and span IDs (requires OpenTelemetry integration)
let context = current_span.context();
let trace_id = context.span().span_context().trace_id();
let span_id = context.span().span_context().span_id();
info!(
trace_id = %trace_id,
span_id = %span_id,
"Working with trace context"
);
// These IDs can be logged, sent to downstream services, etc.
// for distributed trace correlation
}
work_with_trace_ids().instrument(root_span).await;
// Flush telemetry
opentelemetry::global::shutdown_tracer_provider();
}Trace and span IDs enable correlation across services and log aggregation systems.
use tracing::{info, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt().init();
// AUTOMATIC: Using instrument()
let span_auto = span!(Level::INFO, "automatic_span");
async fn automatic_work() {
info!("This is inside the span");
tokio::time::sleep(Duration::from_millis(10)).await;
info!("Still inside the span after await");
}
automatic_work().instrument(span_auto).await;
// MANUAL: Entering and exiting spans (error-prone)
let span_manual = span!(Level::INFO, "manual_span");
let _enter = span_manual.enter(); // Enter the span
info!("This is inside the span");
// PROBLEM: The guard (_enter) keeps the span entered
// across the await point, which is incorrect!
// The span stays entered even when the runtime
// switches to another task.
// This is WRONG for async code:
// tokio::time::sleep(Duration::from_millis(10)).await;
// The span remains entered while other tasks run!
// The correct manual way is complex:
drop(_enter); // Exit before await
tokio::time::sleep(Duration::from_millis(10)).await;
let _enter = span_manual.enter(); // Re-enter after await
info!("Back in span after await");
drop(_enter); // Exit when done
// instrument() handles all of this automatically!
}instrument() correctly manages span lifecycle across await points; manual management is error-prone.
use tracing::{error, info, span, Level, Instrument};
use std::time::Duration;
#[tokio::main]
async fn main() {
tracing_subscriber::fmt().init();
let span = span!(Level::INFO, "operation_with_error");
async fn fallible_work() -> Result<String, &'static str> {
info!("Starting work");
tokio::time::sleep(Duration::from_millis(5)).await;
// Simulate an error
Err("Something went wrong")
}
// The span context is preserved even through errors
let result = fallible_work()
.instrument(span.clone())
.await;
match result {
Ok(value) => info!(value = %value, "Success"),
Err(e) => error!(error = %e, "Failed"),
}
// Using #[instrument] with errors
#[tracing::instrument]
async fn another_fallible() -> Result<i32, String> {
info!("Working");
tokio::time::sleep(Duration::from_millis(5)).await;
Err("Another error".to_string())
}
// The span records the error automatically with #[instrument(err)]
#[tracing::instrument(err)]
async fn with_error_recording() -> Result<i32, String> {
info!("Working with error recording");
tokio::time::sleep(Duration::from_millis(5)).await;
Err("Recorded error".to_string())
}
let _ = with_error_recording().await;
}Spans remain active through error paths; #[instrument(err)] automatically records errors on the span.
How instrument works:
| Phase | Action | |-------|--------| | Before poll | Enter the span (set in thread-local storage) | | During poll | All tracing macros use the current span | | At await point | Span is exited when future yields | | After await | Span is re-entered when future resumes | | After completion | Span is exited and can be recorded |
Key concepts:
| Concept | Description | |---------|-------------| | Span | A unit of work with start/end time and metadata | | Trace | A collection of spans forming a request's journey | | Context | Trace ID, span ID, parent span ID stored in thread-local | | Propagation | Passing context across async boundaries and services |
Common patterns:
// Entry point: create request-scoped span
#[instrument(skip(request))]
async fn handle_request(request: Request) -> Response {
// All work is traced
process(&request).await?;
Ok(Response::new())
}
// Spawned tasks: inherit or create child spans
tokio::spawn(
background_work()
.instrument(span!(Level::INFO, "background"))
);
// External calls: create child spans for out-of-process work
#[instrument]
async fn call_service() {
let span = span!(Level::INFO, "http_call", service = "inventory");
async {
// HTTP client with trace context headers
}
.instrument(span)
.await;
}Key insight: instrument() solves a fundamental problem in async tracingâensuring that span context survives across await points. In synchronous code, a span guard (let _enter = span.enter()) keeps the span active for a lexical scope. In async code, this approach fails because the future may be suspended at an await point and resumed on a different thread, with different code executing in between. The instrument() wrapper enters the span before each poll and exits after each poll, ensuring that regardless of how many times the future is suspended and resumed, the span context is always correct during execution. This enables distributed tracing to work correctly in async Rust: the trace ID established at a service's entry point propagates through all async operations, and when you make an HTTP call to another service, you can inject the current span context into headers, allowing the downstream service to continue the same trace. The #[instrument] attribute macro makes this pattern ergonomic, automatically creating a span from function arguments and optionally recording errors, while instrument() provides explicit control for cases where you need to customize span creation or attach spans to spawned tasks.