Using LogTracer with a tracing subscriber

[jwodder]

How can I write a program that configures a typical tracing subscriber (just using the types from tracing-subscriber) while also using tracing_log::LogTracer to capture log messages from a dependency?

I tried the following minimal code:

use tracing_subscriber::filter::LevelFilter;

fn main() {
    tracing_log::LogTracer::init().unwrap();
    tracing_subscriber::fmt()
        .with_max_level(LevelFilter::TRACE)
        .init();
    log::debug!("This is a log message.");
    tracing::debug!("This is a tracing message.");
}

on Rust 1.76 with these dependencies:

[dependencies]
log = "0.4.20"
tracing = "0.1.40"
tracing-log = "0.2.0"
tracing-subscriber = "0.3.18"

but it fails with:

thread 'main' panicked at /Users/jwodder/.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

Switching the order of the init()'s just changes the error to:

thread 'main' panicked at src/main.rs:7:36:
called `Result::unwrap()` on an `Err` value: SetLoggerError(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

[criccomini]

Seeing the same issue. What am I missing? 😅

[criccomini]

Figured this out. Apparently if you use the default features for tracing_subscriber, it enables tracing-log, which causes SubscriberBuilder.init() to register with the log global logger. This prevents you from using the subscriber along side tracing_log. To fix this, you need to disable the default features for tracing_subscriber:

tracing-subscriber = { version = "0.3", default-features = false }

Here's a look at a diff that works:

diff --git a/Cargo.lock b/Cargo.lock
index 06ed52f..fd19c97 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -3195,6 +3195,7 @@ dependencies = [
  "tokio-test",
  "tokio-util",
  "tracing",
+ "tracing-log",
  "tracing-subscriber",
  "ulid",
  "uuid",
diff --git a/Cargo.toml b/Cargo.toml
index 2c5e1eb..efacb02 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -66,7 +66,8 @@ thiserror = "1.0.63"
 tokio = "1.40.0"
 tokio-util = { version = "0.7.15", default-features = false }
 tracing = "0.1.40"
-tracing-subscriber = "0.3"
+tracing-log = "0.2"
+tracing-subscriber = { version = "0.3", default-features = false }
 thread_local = "1.1.8"
 ulid = "1.2.1"
 uuid = "1.17.0"
diff --git a/slatedb/Cargo.toml b/slatedb/Cargo.toml
index 5c11ff5..3cb1ff9 100644
--- a/slatedb/Cargo.toml
+++ b/slatedb/Cargo.toml
@@ -68,6 +68,7 @@ rstest = { workspace = true }
 tempfile = { workspace = true }
 tokio = { workspace = true, features = ["rt-multi-thread"] }
 tokio-test = { workspace = true }
+tracing-log = { workspace = true }
 tracing-subscriber = { workspace = true, features = ["fmt", "env-filter"] }
 
 [features]
diff --git a/slatedb/src/test_utils.rs b/slatedb/src/test_utils.rs
index ad51fb7..4b665bb 100644
--- a/slatedb/src/test_utils.rs
+++ b/slatedb/src/test_utils.rs
@@ -344,6 +344,7 @@ static INIT_LOGGING: Once = Once::new();
 fn init_tracing() {
     INIT_LOGGING.call_once(|| {
         let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("debug"));
+        tracing_log::LogTracer::init().expect("failed to initialize tracing");
         tracing_subscriber::fmt()
             .with_env_filter(filter)
             .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)

[criccomini]

I should also note, not doing it this way causes structured logging kv-pairs (log::info!(foo, bar:?, baz=blah; "something") to disappear/get dropped. You only see "something" in the logs.

[criccomini]

TBH, I really feel like this is a bug in the way tracing_subscriber's Cargo.toml is set up. tracing_subscriber depends on the tracing_log package. The tracing_log package depends on log:

https://github.com/tokio-rs/tracing/blob/e63ef57f3d686abe3727ddd586eb9af73d6715b7/tracing-log/Cargo.toml#L28C1-L29C1

That dependency does not include support for the log crate's kv features. Consequently, the default behavior when a user creates a library that uses log with the kv feature and logs kv features is that those kv's are silently dropped because the tracing_log crate ignores them.