Why does cargo test show me trace! logs when I specify RUST_LOG=debug?

Question

Why does cargo test show me trace! logs when I specify RUST_LOG=debug?

I'm using SimpleLogger as a test backend, initialized like that (init_logger is called at the beginning of each test function):

static INIT_LOGGER: Once = Once::new();

pub fn init_logger() {
    INIT_LOGGER.call_once(|| {
        SimpleLogger::new().init().unwrap();
    });
}

I run the tests with:

RUST_LOG=debug cargo test

And I see all log messages, INFO, DEBUG...

I'd like to see only the DEBUG messages.

Also, I'd like to see only the messages from my own crate, not from its dependencies, is that possible?

Finomnis · Accepted Answer · 2022-07-09T20:18:24.763

SimpleLogger by default does not react to environment variables.

Use the .env() method to enable that behaviour:

use std::sync::Once;

use simple_logger::SimpleLogger;

static INIT_LOGGER: Once = Once::new();
pub fn init_logger() {
    INIT_LOGGER.call_once(|| {
        SimpleLogger::new().env().init().unwrap();
    });
}

fn main() {
    init_logger();
    log::error!("error");
    log::warn!("warn");
    log::info!("info");
    log::debug!("debug");
    log::trace!("trace");
}

> RUST_LOG=debug cargo run
2022-07-09T14:49:19.733Z ERROR [streamer] error
2022-07-09T14:49:19.733Z WARN [streamer] warn
2022-07-09T14:49:19.733Z INFO [streamer] info
2022-07-09T14:49:19.733Z DEBUG [streamer] debug

> RUST_LOG=info cargo run
2022-07-09T14:49:25.022Z ERROR [streamer] error
2022-07-09T14:49:25.022Z WARN [streamer] warn
2022-07-09T14:49:25.022Z INFO [streamer] info

Or use the much more popular EnvLogger instead.

With EnvLogger you can do exactly what you were asking for; you can enable different log levels for different dependencies. Here is a more detailed description of what can be achieved with EnvLogger.

use std::sync::Once;

static INIT_LOGGER: Once = Once::new();
pub fn init_logger() {
    INIT_LOGGER.call_once(|| {
        env_logger::init();
    });
}

fn main() {
    init_logger();
    log::error!("error");
    log::warn!("warn");
    log::info!("info");
    log::debug!("debug");
    log::trace!("trace");
}

> RUST_LOG=debug cargo run
[2022-07-09T14:52:42Z ERROR streamer] error
[2022-07-09T14:52:42Z WARN  streamer] warn
[2022-07-09T14:52:42Z INFO  streamer] info
[2022-07-09T14:52:42Z DEBUG streamer] debug

> RUST_LOG=info cargo run
[2022-07-09T14:52:46Z ERROR streamer] error
[2022-07-09T14:52:46Z WARN  streamer] warn
[2022-07-09T14:52:46Z INFO  streamer] info

You seem like you know more about logging within Rust tests than most people. If you wouldn't mind taking a look at https://stackoverflow.com/q/73293801/470749 I'd appreciate it. Thanks! — Ryan, Aug 11 '22 at 19:01

Why does cargo test show me trace! logs when I specify RUST_LOG=debug?

1 Answers1