🎓 A1Learner
🔍

Rust Logging

Logging writes log lines that a setting can show or hide. Rust splits logging between the log crate and env_logger.

println! prints everything, every time

No setting can hide a println! line. A finished program prints its debug lines for every user:

println!("backup started");
println!("checking file number 7");
println!("copying file 12 of 40");
println!("backup finished");

Five levels of loudness

From the loudest problem to the finest detail: error!, warn!, info!, debug! and trace!. Each works like println!:

error!("the file would not open");
warn!("the file is nearly full");
info!("backup started");
debug!("checking file number 7");
trace!("entering the copy loop");

Turn the printer on

One line in main installs env_logger. After this, the RUST_LOG variable steers what prints:

fn main() {
    env_logger::init();
    // the rest of main...
}

The filter decides

A program can also set the level itself. This builder keeps info and louder, and prints in a short LEVEL: message shape (writeln! needs use std::io::Write at the top of the file):

env_logger::Builder::new()
    .filter_level(log::LevelFilter::Info)
    .format(|buf, record| writeln!(buf, "{}: {}", record.level(), record.args()))
    .init();

error!("the file would not open");
warn!("the file is nearly full");
info!("backup started");
debug!("checking file number 7");
trace!("entering the copy loop");

Your own variable name

filter_or reads your variable when it is set, and falls back to the level you name when it is not:

let env = env_logger::Env::default().filter_or("BACKUP_LOG", "warn");
env_logger::Builder::from_env(env).init();

Send logs to stdout instead

env_logger::Builder::new()
    .target(env_logger::Target::Stdout)
    .init();

Example

use log::{debug, error, info, trace, warn};
use std::io::Write;

fn main() {
    env_logger::Builder::new()
        .filter_level(log::LevelFilter::Debug)
        .format(|buf, record| writeln!(buf, "{}: {}", record.level(), record.args()))
        .init();

    error!("the backup disk is missing");
    warn!("only 2 GB free on the backup disk");
    info!("backup started");
    debug!("copying file 12 of 40");
    trace!("entering the copy loop");
    println!("backup finished");
}

Key points

  • Add both crates to Cargo.toml: log = "0.4" for the macros, env_logger = "0.11" for the printer
  • Nothing prints until a logger is installed.
  • The log macros alone are silent.
  • Library code can log freely.
  • The final program decides
  • env_logger reads the RUST_LOG environment variable.
  • Run with RUST_LOG=debug cargo run and debug lines appear.
  • No code change and no rebuild
  • With no RUST_LOG set, env_logger shows only error! lines by default
  • Filters can name one module: RUST_LOG=my_app=info,my_app::db=trace keeps the app at info but the db module at trace
  • Log lines go to stderr by default.
  • They never mix into output your program pipes to a file or another program
  • Logging lets a finished program explain itself later, when nobody is watching it.

In this example, a backup tool installs env_logger. It uses its own short format — LEVEL: message. The level is set to Debug. Four of the five log lines print. trace! stays hidden, because trace is quieter than debug. The last line, backup finished, comes from println! and goes to stdout, while the log lines go to stderr. In a terminal they mix together. In a pipe, only backup finished would flow on.

Note

Reach for dbg! while you are hunting one value at your desk (the Debug Printing lesson).

Reach for logging when the program must explain itself later, on someone else's machine.

Try it Yourself

Edit the code, then press Run.

Running is simulated · Rust Playground

Exercise

You run a program with RUST_LOG=warn. Its debug! lines stay invisible. Why?