tracing_subscriber::reload does not realod log max level

[npajkovsky]

Bug Report

I have a simple program like

 use tracing_subscriber::{filter, prelude::*, reload};

  fn main() {
      let (filter, reload_handle) = reload::Layer::new(filter::LevelFilter::WARN);

      let fmt_layer = tracing_subscriber::fmt::layer().with_thread_ids(true);

      tracing_subscriber::registry()
          .with(filter)
          .with(fmt_layer)
          .init();

      reload_handle
          .modify(|filter| *filter = filter::LevelFilter::TRACE)
          .unwrap();

      log::debug!("log");
      log::info!("log");

      tracing::debug!("tracing");
      tracing::info!("tracing");
  }

but it looks like reload_handle.modify just modifies tracing::* level, but not the log::*.

The output of the code is

2023-09-05T13:40:44.898415Z DEBUG ThreadId(01) tracing_test: tracing
2023-09-05T13:40:44.898456Z  INFO ThreadId(01) tracing_test: tracing

but I'm expecting even logs from log::{debug!, info!} after modifying the filter level to TRACE.

I'm also seeing in tracing-subscriber/src/reload.rs

        // 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(),
        ));

but it seems it does not make effect even thought I have enabled appropriate feature.

[dependencies]
tracing = { version = "=0.1.37" }
tracing-subscriber = { version = "=0.3.17", features = ["env-filter", "tracing-log"] }
log = "=0.4.20"

Version

> % cargo tree | rg 'tracing|log'
tracing-test v0.1.0 (/home/nikola/tmp/tracing-test)
├── log v0.4.20
├── tracing v0.1.37
│   ├── tracing-attributes v0.1.26 (proc-macro)
│   └── tracing-core v0.1.31
└── tracing-subscriber v0.3.17
    ├── tracing v0.1.37 (*)
    ├── tracing-core v0.1.31 (*)
    └── tracing-log v0.1.3
        ├── log v0.4.20
        └── tracing-core v0.1.31 (*)

Platform

-> % uname -a
Linux enhance 5.15.0-76-generic #83-Ubuntu SMP Thu Jun 15 19:16:32 UTC 2023 x86_64 GNU/Linux

[npajkovsky]

There's something off with your releasing strategy.

Commit ba7a7f782a07 ("subscriber: set log max level when reloading (#1270)") resolved my issue, but the question is: Why is it not released? The commit is from 2021.

Even doc points to old source code.

https://docs.rs/tracing-subscriber/latest/src/tracing_subscriber/reload.rs.html#308-321

Looks like tracing_subscriber was not correctly released for years.

commit ba7a7f782a079bbf062352d6c3ed3441cecaba81
Author: Eliza Weisman <eliza@buoyant.io>
Date:   Fri Feb 26 14:35:03 2021 -0800

    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 <eliza@buoyant.io>
---
 tracing-subscriber/src/reload.rs                 | 10 ++++++++++
 tracing-subscriber/tests/reload_max_log_level.rs | 36 ++++++++++++++++++++++++++++++++++++
 2 files changed, 46 insertions(+)

diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs
index 361234649b5f..72f5caff62d0 100644
--- a/tracing-subscriber/src/reload.rs
+++ b/tracing-subscriber/src/reload.rs
@@ -162,6 +162,16 @@ impl<S> Handle<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(())
     }

[hawkw]

Hmm, looks like that commit was not correctly backported. I'll fix that.

[npajkovsky]

I don't think it is just one commit.

That commit pops up when I was trying to use master branch. It broke the build, yet it was never released, and it's from 2020.

commit 98ba44c22ee0d5f96f464b2d0fea8d577c69be7f
Author: David Barsky <me@davidbarsky.com>
Date:   Thu Oct 22 15:11:23 2020 -0400

    core: rename Subscriber to Collect (#1015)

    This PR renames the following:

    - `tracing_core::Subscriber` to `tracing_core::Collect`
    - `tracing_subscriber::layer::Layer` to `tracing_subscriber::layer::Subscribe`

    Authored-by: David Barsksy <dbarsky@amazon.com>
    Co-authored-by: Eliza Weisman <eliza@buoyant.io>

[davidbarsky]

I don't think it is just one commit.

That commit pops up when I was trying to use master branch. It broke the build, yet it was never released, and it's from 2020.

commit 98ba44c22ee0d5f96f464b2d0fea8d577c69be7f
Author: David Barsky <me@davidbarsky.com>
Date:   Thu Oct 22 15:11:23 2020 -0400

    core: rename Subscriber to Collect (#1015)

    This PR renames the following:

    - `tracing_core::Subscriber` to `tracing_core::Collect`
    - `tracing_subscriber::layer::Layer` to `tracing_subscriber::layer::Subscribe`

    Authored-by: David Barsksy <dbarsky@amazon.com>
    Co-authored-by: Eliza Weisman <eliza@buoyant.io>

Yes, that one will not be backported until we're ready to release tracing 0.2.

[npajkovsky]

When do you think this will be fixed and released?