tokio-rs / tracing

Application level tracing for Rust.
https://tracing.rs
MIT License
5.4k stars 709 forks source link

SubscriberInitExt trait method set_default doesn't work well during bootstrap with feature tracing-log on #2903

Open wt opened 7 months ago

wt commented 7 months ago

Bug Report

The SubscirberInitExt::set_default methods panics in unexpected ways.

Version

tracing-subscriber 0.3.18

Platform

I run Fedora Rawhide.

Linux 6.8.0-0.rc6.20240227git45ec2f5f6ed3.50.fc41.x86_64 #1 SMP PREEMPT_DYNAMIC Tue Feb 27 14:56:39 UTC 2024 x86_64 GNU/Linux

Crates

tracing 0.1.40 tracing-log 0.2.0

Description

I wanted to create a bootstrap logging environment while I do anything that must be done before finally configuring the global logger. My logging can be changed by commandline args and config files. However, I wanted to have everything that goes to stderr be passed via the tracing macros. I didn't want to do manual write!s before my logging was ready, and I want to use "tracing-log" to make logging macros work well also. I decided to create a bootstrap logging for this bit of time where logging is not yet globally configured for good.

In my implementation, I parse command line args and immediately enter this state. The top of my main looks like this:

#[tokio::main]
async fn main() -> Result<()> {
    let args = Args::parse();

    // create bootstrap tracing subscriber
    let env_filter = tracing_subscriber::filter::EnvFilter::new("debug");
    let bootstrap_subscriber = tracing_subscriber::fmt()
        .with_writer(std::io::stderr)
        .with_env_filter(env_filter)
        .finish();
...

Now I need to set use the bootstrap subscriber as my default logging setup for the time being. I looked into a few options and found the set_default method of the SubscriberInitExt trait. So, I imported the trait and tried the following:

use tracing_subscriber::util::SubscriberInitExt;
let bootstrap_log_sub_guard = bootstrap_subscriber.set_default();

This seems to work okay until later I tried the following:

really_setup_logging(ARGS_DISCOVERED_FROM_CLI_ARGS_AND_CONFIG); //setup global logging
drop(bootstrap_log_sub_guard); // remove the subscriber guard to make the default stop

I get not get a panic while starting.

thread 'main' panicked at $HOME/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-subscriber-0.3.18/src/fmt/mod.rs:517:14:
Unable to install global subscriber: SetLoggerError(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

The error is about setting up a global subscriber. Long story short, some digging indicates that the global logging setup for the log crate is being mucked with by both the call the set_default above and my real config that is performed in the really_setup_logging function.

I wallow for a while in despair. I finally start looking for workaround. Here's what I find. The setdefault method in SubscriberInitExt has the following call: `let = tracing_log::LogTracer::init();`. This sets up a global logging config...which I really don't want right here. I want a default, but not a global config. So, I change change the call to SubscriberInitExt::set_default line in my code shown above to:

let bootstrap_log_sub_guard = tracing::subscriber::set_default(bootstrap_subscriber);

The tracing set_default doesn't do the global log crate setup. It only makes my subscriber the default subscriber. This means that my plan now works, and I can just setup logging and drop the guard.

I personally believe that it would make more sense if the SubscriberInitExt version of set_default just skipped the global log initialization since that global config can only be done once without a panic. Or maybe find a way to not panic when setting up global logging that way.

I did some testing and found that I could use SubscriberInitExt::set_default without a panic after my global logging is properly setup. I am not sure why that is, so maybe the real bug is closer to here.