Logs
Recipe | Crates | Categories |
---|---|---|
Initialize the logger | ||
Enable basic tracing | ||
Combine layers | ||
Configure a custom event formatter | ||
Events | ||
Spans | ||
Add tracing spans to functions | ||
See also |
[tracing.incl: fix (P1)](https://github.com/john-cd/rust_howto/issues/321)
Add to Cargo.toml
[dependencies]
tracing = "0.1"
tracing-subscriber = "0.3"
Initialize the logger
Enable basic tracing
fn main() {
// Filter events at runtime using the value
// of the RUST_LOG environment variable:
// for example, RUST_LOG=debug,my_crate=trace
tracing_subscriber::fmt::init();
// This is equivalent to:
// tracing_subscriber::fmt()
// .with_env_filter(EnvFilter::from_default_env())
// .init();
tracing::info!("tracing configured!");
println!("Done.")
}
Combine layers
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
fn main() {
tracing_subscriber::registry()
.with(tracing_subscriber::fmt::layer())
.with(tracing_subscriber::filter::EnvFilter::new(
std::env::var("RUST_LOG").unwrap_or_else(|_| {
"myproj=debug,axum=debug,tower_http=debug,mongodb=debug".into()
}),
))
.init();
tracing::info!("tracing configured!");
println!("Done.")
}
Or with a custom formatting layer
use tracing_subscriber::filter::EnvFilter;
use tracing_subscriber::fmt;
use tracing_subscriber::prelude::*;
fn main() {
let fmt_layer = fmt::layer().with_target(false);
let filter_layer = EnvFilter::try_from_default_env()
.or_else(|_| EnvFilter::try_new("info"))
.unwrap();
tracing_subscriber::registry()
.with(filter_layer)
.with(fmt_layer)
.init();
}
Configure a custom event formatter
use tracing_subscriber::fmt;
fn main() {
// Configure a custom event formatter
let format = fmt::format()
.with_level(false) // Don't include levels in formatted output
.with_target(false) // Don't include targets
.with_thread_ids(true) // Include the thread ID of the current thread
.with_thread_names(true) // Include the name of the current thread
.compact(); // Use the `Compact` formatting style.
// Create a `fmt` subscriber that uses our custom event format, and
// set it as the default.
tracing_subscriber::fmt().event_format(format).init();
}
Events
use tracing::Level; use tracing::debug; use tracing::error; use tracing::event; use tracing::info; use tracing::trace; use tracing::warn; #[derive(Debug)] struct S; fn main() { event!(Level::INFO, "something happened"); error!("error!"); warn!("warning!"); info!("info!"); debug!("debug info!"); trace!("trace info!"); event!(target: "app_events", Level::TRACE, "something has happened!"); // Records an event with two fields (also works for spans) event!( Level::INFO, answer = 42, question = "life, the universe, and everything" ); // Unlike other fields, `message`'s shorthand initialization is just // the string itself. debug!(excitement = "yay!", "hello!"); // Shorthand for `user = user` let user = "ferris"; event!(Level::TRACE, "login: {}", user); // Note the `?`: `my_struct` will be recorded // using its `fmt::Debug` implementation. let my_struct = S; event!(Level::TRACE, greeting = ?my_struct); }
Spans
use tracing::Level; use tracing::span; fn main() { let span = span!(Level::TRACE, "my_span"); { // Current lexical scope. let _guard = span.enter(); println!( "`enter` returns a RAII guard, which, when dropped, exits the span." ); println!("Any trace events that occur here will occur within the span.") } println!("Dropping the guard exits the span."); }
One-liner with .entered()
:
use tracing::Level; use tracing::span; fn main() { let span = span!(Level::TRACE, "some span").entered(); println!("Code here is within the span"); // optionally, explicitly exit the span, returning it let span = span.exit(); println!("Code here is no longer within the span"); // enter the span again let _span = span.entered(); println!("Code here is within the span"); }
Holding the drop guard returned by Span::enter
across .await
points will result in incorrect traces. Use tracing::span::Span::in_scope
⮳.
use tracing::Instrument; use tracing::debug_span; use tracing::info_span; async fn my_async_function() { let span = info_span!("my_async_function"); // Instrument synchronous code within an async functiom let _some_value = span.in_scope(|| { // Run some synchronous code inside the span... 42 }); // This is okay! // The span has already been exited before we reach the await point. some_other_async_function().await; // Instrument async code async move { // This is correct! If we yield here, the span will be exited, // and re-entered when we resume. some_other_async_function().await; } .instrument(span) // instrument the async block with the span... .await; // ...and await it. let _some_value = some_other_async_function() .instrument(debug_span!("some_other_async_function")) .await; } async fn some_other_async_function() {} #[tokio::main] async fn main() { my_async_function().await; }
Add tracing spans to functions
use tracing::Level; use tracing::event; use tracing::instrument; #[instrument] fn my_function(my_arg: usize) { // This event will be recorded inside a span named `my_function` // with the field `my_arg`. event!(Level::INFO, "inside my_function!"); // ... } // Used on an async function #[instrument(level = "info")] async fn my_async_function() { // This is correct! If we yield here, the span will be exited, // and re-entered when we resume. some_other_async_function().await; } async fn some_other_async_function() {} #[tokio::main] async fn main() { my_function(42); my_async_function().await; }
See also
tracing_journald⮳ provides support for logging tracing
⮳ events natively to journald⮳, preserving any structured information.
[tracing: [tracing-next-steps][c-tracing-next-steps] (P1)](https://github.com/john-cd/rust_howto/issues/322)