Rust Logging with log and tracing

When something goes wrong in a program, you want to know what it was doing just before. That’s what logging is for. A log is like a ship’s logbook: short notes, each with a time and a level of importance, that you can read later to understand what happened.

You could sprinkle println! everywhere, but you’d soon hit its limits. You can’t turn it off without editing code. You can’t say “show me only the warnings”. And it mixes your debug notes into the program’s real output. Rust’s logging crates fix all three problems. On this page you’ll learn the two most popular ones: log (with env_logger) and tracing.

Why not just println!?

Here’s the difference in one picture:

	println!	a logging crate
Turn it on/off without recompiling	No	Yes, with the RUST_LOG variable
Levels (error, warn, info, …)	No	Yes
Shows where the message came from	No	Yes (the module name)
Where it goes	stdout	stderr by default (env_logger)

That last row matters more than it looks. stdout is your program’s real result — the thing someone might pipe into a file or another program. stderr is the side channel for messages about the run. Logs belong on stderr, so my_app > result.txt saves only the result, while the logs still show up in the terminal.

The log facade and env_logger

The log crate gives you five macros, one per level, from most to least serious: error!, warn!, info!, debug!, and trace!. They work just like println! — same {} formatting.

But log on its own prints nothing. It’s a facade: a standard set of macros that every library can use, without choosing how the messages are displayed. Your application picks a logger that actually writes them out. The simplest one is env_logger. Add both to your project:

cargo add log env_logger

[dependencies]
log = "0.4"
env_logger = "0.11"

Now call env_logger::init() once, at the start of main, and log away:

use log::{debug, error, info, warn};

fn divide(a: f64, b: f64) -> Option<f64> {
    debug!("divide called with a={a}, b={b}");
    if b == 0.0 {
        warn!("refusing to divide {a} by zero");
        return None;
    }
    Some(a / b)
}

fn main() {
    env_logger::init();
    info!("calculator starting");

    println!("10 / 4 = {:?}", divide(10.0, 4.0));
    println!("1 / 0 = {:?}", divide(1.0, 0.0));

    error!("this is what an error line looks like");
}

Output:

10 / 4 = Some(2.5)
1 / 0 = None

▶ Try it Yourself

The output above is only stdout — the program’s real result. The log lines go to stderr. In the Playground they appear in the separate “Standard Error” area.

Notice something: by default, env_logger shows only errors. To see more, set the RUST_LOG environment variable when you run the program. Here is what stderr and stdout looked like together when we ran it in a terminal with RUST_LOG=debug cargo run (we replaced each timestamp with … — yours will show the current date and time):

[… INFO  my_app] calculator starting
[… DEBUG my_app] divide called with a=10, b=4
10 / 4 = Some(2.5)
[… DEBUG my_app] divide called with a=1, b=0
[… WARN  my_app] refusing to divide 1 by zero
1 / 0 = None
[… ERROR my_app] this is what an error line looks like

Each log line shows the level and the module it came from (my_app, the crate’s name). The plain lines without brackets are the println! output.

Choosing what you see with RUST_LOG

A level shows that level and everything more serious. So RUST_LOG=warn shows warnings and errors; RUST_LOG=trace shows everything.

RUST_LOG=debug cargo run     # debug, info, warn, error
RUST_LOG=warn cargo run      # only warn and error
RUST_LOG=off cargo run       # no logs at all

On Windows PowerShell, set the variable first: $env:RUST_LOG="debug"; cargo run.

You can also filter by module. This is great when a library is too chatty, or when you only care about one part of your code. Here’s a program with a db module:

use log::{debug, info};

mod db {
    use log::{debug, trace};

    pub fn find_user(id: u32) -> Option<&'static str> {
        trace!("looking up user {id}");
        let name = match id {
            1 => Some("Ada"),
            2 => Some("Linus"),
            _ => None,
        };
        debug!("lookup result: {name:?}");
        name
    }
}

fn main() {
    env_logger::init();
    info!("server starting");

    for id in [1, 3] {
        match db::find_user(id) {
            Some(name) => println!("user {id}: {name}"),
            None => println!("user {id}: not found"),
        }
    }

    debug!("all lookups done");
}

Output:

user 1: Ada
user 3: not found

▶ Try it Yourself

Some filters we tried, and what they printed to stderr (timestamps replaced with …):

$ RUST_LOG=my_app=trace cargo run       # everything from our crate
[… INFO  my_app] server starting
[… TRACE my_app::db] looking up user 1
[… DEBUG my_app::db] lookup result: Some("Ada")
user 1: Ada
[… TRACE my_app::db] looking up user 3
[… DEBUG my_app::db] lookup result: None
user 3: not found
[… DEBUG my_app] all lookups done

$ RUST_LOG=my_app::db=debug cargo run   # only the db module, debug and up
[… DEBUG my_app::db] lookup result: Some("Ada")
user 1: Ada
[… DEBUG my_app::db] lookup result: None
user 3: not found

You can combine rules with commas: RUST_LOG=info,my_app::db=trace means “info for everything, but trace for the db module”. One small trap: the filter uses the crate name with underscores. A package called my-app logs as my_app.

Setting a default level in code

Often you want info to show even when RUST_LOG isn’t set. Use env_logger::Builder instead of init(). You can also turn off the timestamp, which is handy for short tools:

use env_logger::Env;
use log::{debug, info};

fn main() {
    // Show `info` and above unless RUST_LOG says otherwise.
    env_logger::Builder::from_env(Env::default().default_filter_or("info"))
        .format_timestamp(None)
        .init();

    info!("app started");
    debug!("you only see this with RUST_LOG=debug");

    let total: u32 = (1..=10).sum();
    println!("total = {total}");
}

Output:

total = 55

▶ Try it Yourself

With no timestamp, the real stderr from cargo run is short and clean:

[INFO  my_app] app started

Structured logging with tracing

log gives you lines of text. tracing gives you events with data, grouped into spans. It was built by the Tokio team, and it’s what async web frameworks like axum use. Add it like this:

cargo add tracing tracing-subscriber

Three ideas to learn:

• Events are like log lines: info!, warn!, and friends, same names as in log.
• Fields attach data as key = value: info!(user_id = 42, "logged in"). Tools can search and filter on these fields, instead of parsing text.
• Spans describe a period of work, like “handling order 7”. Every event inside a span is tagged with it.

Like log, tracing needs a subscriber to display anything. tracing_subscriber::fmt() is the standard one. One surprise: it writes to stdout by default, so we send it to stderr with .with_writer(std::io::stderr):

use tracing::{info, info_span, warn};

fn main() {
    tracing_subscriber::fmt()
        .with_writer(std::io::stderr)
        .init();

    info!(user_id = 42, "logged in");

    let span = info_span!("checkout", order_id = 7);
    let _guard = span.enter();

    let items = [1200, 350, 999];
    let total: u32 = items.iter().sum();
    info!(items = items.len(), total, "cart totalled");

    if total > 2000 {
        warn!(total, limit = 2000, "order needs manual review");
    }

    println!("order total: {total}");
}

Output:

order total: 2549

▶ Try it Yourself

Here’s the stderr from our run (timestamps replaced with …, colors removed):

…  INFO my_app: logged in user_id=42
…  INFO checkout{order_id=7}: my_app: cart totalled items=3 total=2549
…  WARN checkout{order_id=7}: my_app: order needs manual review total=2549 limit=2000

See how the last two lines start with checkout{order_id=7}? That’s the span. While _guard is alive, every event is “inside” the checkout. Writing just total is shorthand for total = total.

#[instrument]: a span for every call

Creating spans by hand gets tiring. Put #[instrument] on a function, and tracing creates a span for each call, with the arguments recorded as fields (they need to implement Debug):

use tracing::{debug, info, instrument};

#[instrument]
fn apply_discount(price: u32, percent: u32) -> u32 {
    let off = price * percent / 100;
    debug!(off, "discount computed");
    price - off
}

fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::DEBUG)
        .with_writer(std::io::stderr)
        .init();

    let final_price = apply_discount(2500, 10);
    info!(final_price, "done");
    println!("final price: {final_price}");
}

Output:

final price: 2250

▶ Try it Yourself

stderr from our run:

… DEBUG apply_discount{price=2500 percent=10}: my_app: discount computed off=250
…  INFO my_app: done final_price=2250

The fmt() subscriber shows info and above unless you tell it otherwise — that’s why we set .with_max_level(tracing::Level::DEBUG). If you want RUST_LOG to work like it does with env_logger, turn on the env-filter feature and use EnvFilter:

[dependencies]
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }

use tracing_subscriber::EnvFilter;

tracing_subscriber::fmt()
    .with_env_filter(EnvFilter::from_default_env())
    .with_writer(std::io::stderr)
    .init();

Which one should you pick?

• Small CLI tool or script? log + env_logger. Tiny setup, plain text, done.
• Web server, async code, or many tasks at once? tracing. Spans keep track of which request a message belongs to, even when hundreds run at the same time.
• Writing a library? Use only the macros (log or tracing) and never call init(). The application decides how logs are shown.

You don’t have to choose forever. tracing-subscriber’s default setup also picks up messages from the log crate, so libraries using either one show up together.

Common mistakes

Forgetting to set up a logger. If you never call env_logger::init() (or a tracing subscriber’s init()), the macros compile fine and print… nothing. No error, no warning. If your logs vanish, check this first — and then check RUST_LOG.

Calling init() twice. There can only be one global logger. The second call panics. This is the real message:

thread 'main' (12345) panicked at …/env_logger-0.11.11/src/logger.rs:901:16:
env_logger::init should not be called after logger initialized: SetLoggerError(())

Call it once, at the very top of main. In tests, use let _ = env_logger::builder().is_test(true).try_init();, which returns an error instead of panicking.

Dropping the span guard right away. let _ = span.enter(); looks harmless, but _ is not a variable name — the guard is dropped on the same line, so the span ends immediately. Our run printed INFO my_app: handling request with no span at all. Give the guard a name, like let _guard = span.enter();, so it lives until the end of the scope.

Recap

• Use a logging crate instead of println! so you can filter by level and keep logs on stderr, away from your real output.
• log gives you error!, warn!, info!, debug!, trace!; env_logger::init() prints them.
• RUST_LOG controls what you see: RUST_LOG=debug, RUST_LOG=my_app=trace, RUST_LOG=info,my_app::db=trace.
• tracing adds structured fields (info!(user_id = 42, "logged in")) and spans; #[instrument] makes a span per function call.
• Libraries use the macros only; the application sets up the logger once.

Quick check

Quick check

1. You run a program that uses env_logger without setting RUST_LOG. Which log lines do you see?

All of them Only info! and above Only error! None at all

2. Where does env_logger write log messages by default?

stdout stderr A file called log.txt

3. What does RUST_LOG=warn show?

Only warnings Warnings and everything less serious Warnings and errors

4. What does putting #[instrument] on a function do?

Times the function and prints the duration Creates a span for each call, with the arguments as fields Makes the function run faster Turns on logging for the whole program

5. You're writing a library crate. What should it do about logging?

Use the logging macros, but let the application set up the logger Call env_logger::init() when the library loads Use println! so it always shows

Score: 0 / 5

Read more

• log crate docs — the five macros and how the facade works, including advice for library authors.
• env_logger docs — the full RUST_LOG syntax and every Builder option.
• tracing docs — spans, events, fields, and #[instrument] in depth.
• tracing-subscriber docs — formatting options, EnvFilter, and JSON output.
• Getting started with Tracing — Tokio — a friendly walkthrough from the team that maintains tracing.