feat: Add tracing-rs-compat feature with tracing compat logging drain

Author: lpraneis

Cargo.toml

@@ -69,6 +69,8 @@ tokio = "1.41.0"
 thread_local = "1.1"
 tikv-jemallocator = "0.5"
 tikv-jemalloc-ctl = "0.5"
+tracing-slog = "0.3.0"
+tracing-subscriber = "0.3"
 yaml-merge-keys = "0.5"
 
 # needed for minver

foundations/Cargo.toml

@@ -164,6 +164,10 @@ testing = ["dep:foundations-macros"]
 # Enables panicking when too much nesting is reached on the logger
 panic_on_too_much_logger_nesting = []
 
+# Enables compatibility with `tracing-rs` by adding the ability to configure a
+# logging drain that forwards logs
+tracing-rs-compat = ["dep:tracing-slog"]
+
 [package.metadata.docs.rs]
 all-features = true
 rustdoc-args = ["--cfg", "docsrs", "--cfg", "tokio_unstable", "--cfg", "foundations_unstable"]
@@ -205,6 +209,7 @@ slog-async = { workspace = true, optional = true }
 slog-json = { workspace = true, optional = true }
 slog-term = { workspace = true, optional = true }
 socket2 = { workspace = true, optional = true }
+tracing-slog = { workspace = true, optional = true }
 thread_local = { workspace = true, optional = true }
 tokio = { workspace = true, optional = true, features = ["sync", "rt"] }
 tonic = { workspace = true, optional = true, features = ["channel", "transport"] }
@@ -243,6 +248,7 @@ tempfile = { workspace = true }
 tokio = { workspace = true, features = ["macros", "rt-multi-thread"] }
 ipnetwork = { workspace = true }
 nix = { workspace = true , features = ["fs"] }
+tracing-subscriber = { workspace = true }
 
 [build-dependencies]
 bindgen = { workspace = true, features = ["runtime"], optional = true }

foundations/src/telemetry/log/init.rs

@@ -107,6 +107,10 @@ pub(crate) fn init(service_info: &ServiceInfo, settings: &LoggingSettings) -> Bo
             let drain = build_json_log_drain(buf);
             AsyncDrain::new(drain).chan_size(CHANNEL_SIZE).build()
         }
+        #[cfg(feature = "tracing-rs-compat")]
+        (LogOutput::TracingRsCompat, _) => AsyncDrain::new(tracing_slog::TracingSlogDrain {})
+            .chan_size(CHANNEL_SIZE)
+            .build(),
     };
 
     let root_drain = get_root_drain(settings, Arc::new(async_drain.fuse()));

foundations/src/telemetry/log/testing.rs

@@ -2,7 +2,7 @@ use crate::telemetry::log::init::{apply_filters_to_drain, LogHarness};
 use crate::telemetry::log::internal::LoggerWithKvNestingTracking;
 use crate::telemetry::settings::LoggingSettings;
 use parking_lot::RwLock as ParkingRwLock;
-use slog::{Drain, Key, Level, Logger, Never, OwnedKVList, Record, Serializer, KV};
+use slog::{Discard, Drain, Key, Level, Logger, Never, OwnedKVList, Record, Serializer, KV};
 use std::fmt::Arguments;
 use std::sync::{Arc, RwLock};
 
@@ -36,11 +36,16 @@ impl Serializer for TestFieldSerializer {
     }
 }
 
-struct TestLogDrain {
+struct TestLogDrain<D> {
     records: TestLogRecords,
+    /// Optional drain to forward logs to after recording in the test log
+    forward: Option<D>,
 }
 
-impl Drain for TestLogDrain {
+impl<D> Drain for TestLogDrain<D>
+where
+    D: Drain<Ok = (), Err = Never>,
+{
     type Ok = ();
     type Err = Never;
 
@@ -56,6 +61,10 @@ impl Drain for TestLogDrain {
             fields: serializer.fields,
         });
 
+        if let Some(forward_drain) = &self.forward {
+            let _ = forward_drain.log(record, kv);
+        }
+
         Ok(())
     }
 }
@@ -65,8 +74,43 @@ pub(crate) fn create_test_log(
 ) -> (LoggerWithKvNestingTracking, TestLogRecords) {
     let log_records = Arc::new(RwLock::new(vec![]));
 
+    let drain: TestLogDrain<Discard> = TestLogDrain {
+        records: Arc::clone(&log_records),
+        forward: None,
+    };
+
+    let drain = Arc::new(apply_filters_to_drain(drain, settings));
+    let log = LoggerWithKvNestingTracking::new(Logger::root(Arc::clone(&drain), slog::o!()));
+
+    let _ = LogHarness::override_for_testing(LogHarness {
+        root_log: Arc::new(ParkingRwLock::new(log.clone())),
+        root_drain: drain,
+        settings: settings.clone(),
+        log_scope_stack: Default::default(),
+    });
+
+    (log, log_records)
+}
+
+/// Create a test log with a tracing-rs compat drain installed in addition to the test drain
+#[cfg(feature = "tracing-rs-compat")]
+pub(crate) fn create_test_log_for_tracing_compat(
+    settings: &LoggingSettings,
+) -> (LoggerWithKvNestingTracking, TestLogRecords) {
+    use tracing_slog::TracingSlogDrain;
+
+    assert!(matches!(
+        settings.output,
+        crate::telemetry::settings::LogOutput::TracingRsCompat
+    ));
+
+    let base_drain = TracingSlogDrain {};
+
+    let log_records = Arc::new(RwLock::new(vec![]));
+
     let drain = TestLogDrain {
         records: Arc::clone(&log_records),
+        forward: Some(base_drain.fuse()),
     };
 
     let drain = Arc::new(apply_filters_to_drain(drain, settings));

foundations/src/telemetry/settings/logging.rs

@@ -51,6 +51,13 @@ pub enum LogOutput {
     ///
     /// File will be created if it doesn't exist and overwritten otherwise.
     File(PathBuf),
+
+    ///Install a logging drain that forwards to `tracing-rs`
+    ///
+    ///WARN: If this output format is used, the settings in [`LoggingSettings`] other than the
+    ///verbosity will not be respected
+    #[cfg(feature = "tracing-rs-compat")]
+    TracingRsCompat,
 }
 
 /// Format of the log output.

foundations/src/telemetry/testing.rs

@@ -88,6 +88,18 @@ impl TestTelemetryContext {
         self.log_records = log_records;
     }
 
+    /// Overrides the logging settings on the test telemetry context with the tracing-rs compat
+    /// layer. The `logging_settings` provided must use the [tracing compat] output format
+    ///
+    /// [tracing compat]: super::settings::LogOutput::TracingRsCompat
+    #[cfg(all(feature = "logging", feature = "tracing-rs-compat"))]
+    pub fn set_tracing_rs_log_drain(&mut self, logging_settings: LoggingSettings) {
+        use crate::telemetry::log::testing::create_test_log_for_tracing_compat;
+        let (log, log_records) = { create_test_log_for_tracing_compat(&logging_settings) };
+        *self.inner.log.write() = log;
+        self.log_records = log_records;
+    }
+
     /// Overrides the tracing settings on the test telemetry context, creating a new test tracer
     /// with the settings
     #[cfg(feature = "tracing")]

foundations/tests/logging.rs

@@ -72,3 +72,82 @@ fn test_not_exceed_limit_kv_nesting(_ctx: TestTelemetryContext) {
         set_verbosity(LogVerbosity::Info).expect("set_verbosity");
     }
 }
+
+#[cfg(feature = "tracing-rs-compat")]
+mod tracing_rs_compat {
+    use std::io;
+    use std::sync::{Arc, Mutex};
+
+    use foundations::telemetry::log::{warn, TestLogRecord};
+    use foundations::telemetry::settings::LoggingSettings;
+    use foundations::telemetry::TelemetryContext;
+    use tracing_subscriber::filter::LevelFilter;
+    use tracing_subscriber::util::SubscriberInitExt as _;
+
+    struct TestWriter {
+        log_entries: Arc<Mutex<Vec<String>>>,
+    }
+
+    impl TestWriter {
+        fn with_entries(entries: Arc<Mutex<Vec<String>>>) -> Self {
+            Self {
+                log_entries: entries,
+            }
+        }
+    }
+
+    impl io::Write for TestWriter {
+        fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+            let s = String::from_utf8(buf.to_vec()).unwrap();
+            self.log_entries.lock().unwrap().push(s.trim().to_string());
+            Ok(buf.len())
+        }
+
+        fn flush(&mut self) -> io::Result<()> {
+            unimplemented!()
+        }
+    }
+
+    #[test]
+    fn test_tracing_rs_compat() {
+        let entries = Arc::new(Mutex::new(Vec::new()));
+        let tracing_log_entries = entries.clone();
+        let _subscriber = tracing_subscriber::fmt()
+            .with_max_level(LevelFilter::TRACE)
+            .with_writer(move || TestWriter::with_entries(entries.clone()))
+            .without_time()
+            .with_level(true)
+            .with_ansi(false)
+            .set_default();
+
+        let settings = LoggingSettings {
+            output: foundations::telemetry::settings::LogOutput::TracingRsCompat,
+            ..Default::default()
+        };
+
+        let mut ctx = TelemetryContext::test();
+        ctx.set_tracing_rs_log_drain(settings);
+
+        let _scope = ctx.scope();
+
+        warn!("compat-layer-works");
+
+        // Validate slog is seeing all of the records
+        let slog_records = ctx.log_records();
+        let expected_slog_records = TestLogRecord {
+            level: slog::Level::Warning,
+            message: "compat-layer-works".to_string(),
+            fields: vec![],
+        };
+
+        assert_eq!(*slog_records, vec![expected_slog_records]);
+
+        let tracing_record = tracing_log_entries
+            .lock()
+            .unwrap()
+            .first()
+            .cloned()
+            .unwrap();
+        assert!(tracing_record.contains("WARN slog: compat-layer-works"));
+    }
+}