Dynamically add more log layers at run-time

[emilk]

Feature Request

Crates

tracing-subscriber

Motivation

There are many places I want to pipe my log events:

• stderr
• a log file
• The GUI
• the network
• …

These can all be implemented as Layers.

The first thing I want to add is the stderr and file layers. The GUI and the network layers I want to add later once the GUI and network connections are up and running. That way any problems with the GUI/network setup is properly logged to stdout and to file.

In other words: I want to dynamically add layers as the program runs.

Proposal

I propose some sort of simple API along the lines of tracing_subscriber::registry().add(layer);

Prior art

My own C++ logging Loguru has a simple method for adding new log sinks (https://emilk.github.io/loguru/index.html#callbacks):

loguru::add_callback("network_logger", user_data, logging_function, loguru::Verbosity_INFO);

This lets different sub-modules of an application can easily add new log sinks at will.

Alternatives

As I was trying to get this work, several helpful people on Discord pointed me towards tracing_subscriber::reload.

I've tried to get it to work, but so far I've failed. My code thus far:

use tracing_subscriber::prelude::*;

let stdout_layer = tracing_subscriber::fmt::layer().with_filter(tracing_subscriber::EnvFilter::from_default_env());
    
let tracing_layers: Vec<Box<dyn tracing_subscriber::layer::Layer<_> + 'static> = vec![Box::new(stdout_layer)];
let (tracing_layers, reload_handle) = tracing_subscriber::reload::Layer::new(tracing_layers);
tracing_subscriber::registry().with(tracing_layers).init();

// set up GUI or network connect or similar, then:

reload_handle.modify(|layers| {
    let gui_layer = GuiLayer::new(gui_handle);
    layers.push(Box::new(gui_layer));
});

There are several issues with this approach:

• It is using a lot of different features that are hard to find ("Vec implements Layer!")
• It is too difficult to use (I can't get it to compile)
• It requires one to keep track of the reload_handle
• It is VERY verbose

Perhaps all the above issues could be solved by an tracing_subscriber expert plus a little bit of documentation. I don't know - I'm not an expert :)

The error message for the above code:

 1  error[E0277]: the size for values of type `dyn tracing_subscriber::Layer<tracing_subscriber::Registry>` cannot be known at compilation time                                                                                              ▐
     --> examples/rust/api_demo/src/main.rs:652:41                                                                                                                                                                                           ▐
      |                                                                                                                                                                                                                                      ▐
 652  |     tracing_subscriber::registry().with(tracing_layers).init();
      |                                    ---- ^^^^^^^^^^^^^^ doesn't have a size known at compile-time
      |                                    |
      |                                    required by a bound introduced by this call
      |
      = help: the trait `std::marker::Sized` is not implemented for `dyn tracing_subscriber::Layer<tracing_subscriber::Registry>`
      = help: the trait `tracing_subscriber::Layer<S>` is implemented for `tracing_subscriber::reload::Layer<L, S>`
      = note: required for `std::boxed::Box<dyn tracing_subscriber::Layer<tracing_subscriber::Registry>>` to implement `tracing_subscriber::Layer<tracing_subscriber::Registry>`
      = note: 2 redundant requirements hidden
      = note: required for `tracing_subscriber::reload::Layer<std::vec::Vec<std::boxed::Box<dyn tracing_subscriber::Layer<...>>>, ...>` to implement `tracing_subscriber::Layer<tracing_subscriber::Registry>`
      = note: the full type name has been written to '/Users/emilk/code/rerun/rerun/target/debug/deps/api_demo-118a8d78b3eddbda.long-type-14231036155949571826.txt'
 note: required by a bound in `tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt::with`
     --> /Users/emilk/.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-subscriber-0.3.16/src/layer/mod.rs:1485:12
      |
 1485 |         L: Layer<Self>,
      |            ^^^^^^^^^^^ required by this bound in `tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt::with`

[emilk]

Hayden helped me on Discord to get it to compile:

fn tracing_init() {
    use tracing_subscriber::prelude::*;
    use tracing_subscriber::{filter, fmt, registry, reload};

    let stdout_layer = fmt::Layer::default()
        .with_filter(filter::LevelFilter::INFO)
        .boxed();

    let tracing_layers = vec![stdout_layer];
    let (tracing_layers, reload_handle) = reload::Layer::new(tracing_layers);

    registry().with(tracing_layers).init();

    tracing::info!("before reload");

    let reload_result = reload_handle.modify(|layers| {
        let json_layer = fmt::Layer::default()
            .json()
            .with_filter(filter::LevelFilter::INFO)
            .boxed();
        (*layers).push(json_layer);
    });
    match reload_result {
        Ok(_) => {} // Great!
        Err(err) => tracing::warn!("Unable to add new layer: {}", err),
    }

    tracing::info!("after reload");
}

But according to Hayden, it panics at runtime, so this is still an issue.

[pl4nty]

+1, I've run into this when adding https://github.com/tokio-rs/tracing-opentelemetry to an existing app. It has an early stdout to ensure network init issues are captured - this might be a common scenario

[Yongle-Fu]

type SimplifiedHandle = reload::Handle<
    LevelFilter,
    fmt::Layer<Registry, DefaultFields, Format<Full, SystemTime>, Stdout>,
>;

lazy_static! {
    static ref RELOAD_HANDLE: Option<SimplifiedHandle> = None;
}

pub fn initialize_logging(level: i32) {
    // Create a LevelFilter and a reload::Layer
    // let (level_filter, reload_handle) = reload::Layer::new(level_to_filter(level));

    // Update the static handle.
    // *RELOAD_HANDLE = Some(reload_handle);

    let file_fmt_layer = fmt::Layer::default()
        .with_level(false)
        .with_writer(CallbackWriter)
        .with_timer(WithoutTimeFormat)
        .with_filter(level_to_filter(level)); // Use the same level filter

    let console_fmt_layer = fmt::Layer::default()
        .with_file(true)
        .with_line_number(true)
        .with_writer(std::io::stdout)
        .with_timer(CustomTimeFormat)
        .with_filter(level_to_filter(level)); // Use the same level filter

    // let subscriber = Registry::default().with(level_filter);
    let subscriber = Registry::default()
        .with(file_fmt_layer)
        .with(console_fmt_layer);

    tracing::subscriber::set_global_default(subscriber).expect("Failed to set subscriber");
}

pub fn update_logging_level(level: i32) {
    let level_filter = level_to_filter(level);

    if let Some(reload_handle) = &*RELOAD_HANDLE {
        reload_handle
            .modify(|filter| *filter = level_filter)
            .expect("Failed to update logging level");
    }
}

fn level_to_filter(level: i32) -> LevelFilter {
    match level {
        0 => LevelFilter::ERROR,
        1 => LevelFilter::WARN,
        2 => LevelFilter::INFO,
        3 => LevelFilter::DEBUG,
        4 => LevelFilter::TRACE,
        _ => LevelFilter::INFO,
    }
}

how to save a reload_handle, need help

[Yongle-Fu]

found correct usage 😸

lazy_static! {
    static ref IS_INITIALIZED: AtomicBool = AtomicBool::new(false);
    static ref RELOAD_HANDLE: Mutex<Option<reload::Handle<filter::LevelFilter, Registry>>> =
        Mutex::new(None);
}

pub fn setup_logging(level: i32) {
    if IS_INITIALIZED.load(Ordering::Acquire) {
        update_logging_level(level);
        return;
    }

    let result = IS_INITIALIZED.compare_exchange(false, true, Ordering::Acquire, Ordering::Relaxed);
    match result {
        Ok(_) => {
            let (level_filter, reload_handle) = reload::Layer::new(level_to_filter(level));
            set_reload_handle(reload_handle);

            tracing_subscriber::registry()
                .with(level_filter)
                .with(
                    fmt::Layer::default()
                        .with_level(false)
                        .with_writer(CStringWriter)
                        .with_timer(WithoutTimeFormat),
                )
                .with(
                    fmt::Layer::default()
                        .with_file(true)
                        .with_line_number(true)
                        .with_timer(CustomTimeFormat),
                )
                .init();
        }
        Err(_) => {
            // if the logging has already been initialized, just update the logging level
            update_logging_level(level);
        }
    }
}

pub fn update_logging_level(level: i32) {
    if let Some(reload_handle) = &*RELOAD_HANDLE.lock().unwrap() {
        reload_handle
            .modify(|filter| *filter = level_to_filter(level))
            .expect("Failed to update logging level");
    }
}

fn set_reload_handle(reload_handle: reload::Handle<filter::LevelFilter, Registry>) {
    let mut handle = RELOAD_HANDLE.lock().unwrap();
    *handle = Some(reload_handle);
}