From 6f08af07f249a88aa5b34be98c3eb596aef9fc15 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 26 Feb 2021 14:35:03 -0800 Subject: [PATCH] subscriber: set `log` max level when reloading (#1270) This modifies the `tracing_subscriber::reload` layer to also set the `log` crate's max level with the current max `tracing` level filter after reloading. If reloading the subscriber caused the max `tracing` level to change, this ensures that the change is propagated to the `log` crate as well. In the case where the max level was made more verbose, this will ensure that `log` records which were previously disabled are enabled correctly; in the case where it was made less verbose, this improve performance by not having to perfrom more costly filtering for those `log` records. The `log` max level is set only after rebuilding the callsite interest cache, which is what sets the max `tracing` level filter. This ensures that we pass the latest state to the `log` crate. Signed-off-by: Eliza Weisman --- tracing-subscriber/src/reload.rs | 10 +++++ .../tests/reload_max_log_level.rs | 37 +++++++++++++++++++ 2 files changed, 47 insertions(+) create mode 100644 tracing-subscriber/tests/reload_max_log_level.rs diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index 096f83d38a..d926c78f5f 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -317,6 +317,16 @@ impl Handle { drop(lock); callsite::rebuild_interest_cache(); + + // If the `log` crate compatibility feature is in use, set `log`'s max + // level as well, in case the max `tracing` level changed. We do this + // *after* rebuilding the interest cache, as that's when the `tracing` + // max level filter is re-computed. + #[cfg(feature = "tracing-log")] + tracing_log::log::set_max_level(tracing_log::AsLog::as_log( + &crate::filter::LevelFilter::current(), + )); + Ok(()) } diff --git a/tracing-subscriber/tests/reload_max_log_level.rs b/tracing-subscriber/tests/reload_max_log_level.rs new file mode 100644 index 0000000000..69230f0013 --- /dev/null +++ b/tracing-subscriber/tests/reload_max_log_level.rs @@ -0,0 +1,37 @@ +#![cfg(all(feature = "env-filter", feature = "tracing-log"))] + +use tracing::{self, Level}; +use tracing_mock::{expect, subscriber}; +use tracing_subscriber::{filter::LevelFilter, prelude::*, reload}; + +#[test] +fn reload_max_log_level() { + let (subscriber, finished) = subscriber::mock() + .event(expect::event().at_level(Level::INFO)) + .event(expect::event().at_level(Level::DEBUG)) + .event(expect::event().at_level(Level::INFO)) + .only() + .run_with_handle(); + let (filter, reload_handle) = reload::Layer::new(LevelFilter::INFO); + subscriber.with(filter).init(); + + assert!(log::log_enabled!(log::Level::Info)); + assert!(!log::log_enabled!(log::Level::Debug)); + assert!(!log::log_enabled!(log::Level::Trace)); + + log::debug!("i'm disabled"); + log::info!("i'm enabled"); + + reload_handle + .reload(Level::DEBUG) + .expect("reloading succeeds"); + + assert!(log::log_enabled!(log::Level::Info)); + assert!(log::log_enabled!(log::Level::Debug)); + assert!(!log::log_enabled!(log::Level::Trace)); + + log::debug!("i'm enabled now"); + log::info!("i'm still enabled, too"); + + finished.assert_finished(); +}