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 <[email protected]>

Author: hawkw

tracing-subscriber/src/reload.rs

@@ -317,6 +317,16 @@ impl<L, S> Handle<L, S> {
         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(())
     }
 

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();
+}