Merge pull request #2 from rerun-io/captured-identifiers-in-format-st…

…rings

Support captured identifiers in format strings

README.md

@@ -41,19 +41,19 @@ use log_once::{info_once, warn_once};
 
 pub fn shave_the_yak(yaks: &[Yak]) {
     for yak in yaks {
-        info!(target: "yak_events", "Commencing yak shaving for {:?}", yak);
+        info!(target: "yak_events", "Commencing yak shaving for {yak:?}");
 
         loop {
             match find_a_razor() {
                 Ok(razor) => {
                     // This will only appear once in the logger output for each razor
-                    info_once!("Razor located: {}", razor);
+                    info_once!("Razor located: {razor}");
                     yak.shave(razor);
                     break;
                 }
                 Err(err) => {
                     // This will only appear once in the logger output for each error
-                    warn_once!("Unable to locate a razor: {}, retrying", err);
+                    warn_once!("Unable to locate a razor: {err}, retrying");
                 }
             }
         }

src/lib.rs

@@ -26,19 +26,19 @@
 //! # fn find_a_razor() -> Result<u32, u32> { Ok(1) }
 //! pub fn shave_the_yak(yaks: &[Yak]) {
 //!     for yak in yaks {
-//!         info!(target: "yak_events", "Commencing yak shaving for {:?}", yak);
+//!         info!(target: "yak_events", "Commencing yak shaving for {yak:?}");
 //!
 //!         loop {
 //!             match find_a_razor() {
 //!                 Ok(razor) => {
 //!                     // This will only appear once in the logger output for each razor
-//!                     info_once!("Razor located: {}", razor);
+//!                     info_once!("Razor located: {razor}");
 //!                     yak.shave(razor);
 //!                     break;
 //!                 }
 //!                 Err(err) => {
 //!                     // This will only appear once in the logger output for each error
-//!                     warn_once!("Unable to locate a razor: {}, retrying", err);
+//!                     warn_once!("Unable to locate a razor: {err}, retrying");
 //!                 }
 //!             }
 //!         }
@@ -48,25 +48,34 @@
 //! # fn main() {}
 //! ```
 
-extern crate log;
+// We re-export the log crate so that the log_once macros can use it directly.
+// That way users don't need to depend on `log` explicitly.
+// This is especially nice for people who use `tracing` for logging, but still use `log_once`.
+pub use log;
+
 pub use log::Level;
 
 use std::collections::BTreeSet;
 use std::sync::{Mutex, MutexGuard, PoisonError};
 
 #[doc(hidden)]
 pub struct __MessagesSet {
-    inner: Mutex<BTreeSet<String>>
+    inner: Mutex<BTreeSet<String>>,
 }
 
 impl __MessagesSet {
-    pub fn new() -> __MessagesSet {
-        __MessagesSet {
-            inner: Mutex::new(BTreeSet::new())
+    #[must_use]
+    pub fn new() -> Self {
+        Self {
+            inner: Mutex::new(BTreeSet::new()),
         }
     }
 
-    pub fn lock(&self) -> Result<MutexGuard<BTreeSet<String>>, PoisonError<MutexGuard<BTreeSet<String>>>> {
+    /// # Errors
+    /// Mutex poisoning.
+    pub fn lock(
+        &self,
+    ) -> Result<MutexGuard<BTreeSet<String>>, PoisonError<MutexGuard<BTreeSet<String>>>> {
         self.inner.lock()
     }
 }
@@ -94,21 +103,21 @@ macro_rules! log_once {
             &(*__SEEN_MESSAGES)
         }
     });
-    (target: $target:expr, $lvl:expr, $message:expr) => ({
+
+    // log_once!(target: "my_target", Level::Info, "Some {}", "logging")
+    (target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
+        let message = format!($($arg)+);
         #[allow(non_snake_case)]
         let __SEEN_MESSAGES = $crate::log_once!(@CREATE STATIC);
         let mut seen_messages = __SEEN_MESSAGES.lock().expect("Mutex was poisonned");
-        let event = String::from(stringify!($target)) + stringify!($lvl) + $message.as_ref();
+        let event = String::from(stringify!($target)) + stringify!($lvl) + message.as_ref();
         if seen_messages.insert(event) {
-            log::log!(target: $target, $lvl, "{}", $message);
+            $crate::log::log!(target: $target, $lvl, "{}", message);
         }
     });
-    (target: $target:expr, $lvl:expr, $format:expr, $($arg:tt)+) => ({
-        let message = format!($format, $($arg)+);
-        $crate::log_once!(target: $target, $lvl, message);
-    });
-    ($lvl:expr, $message:expr) => ($crate::log_once!(target: module_path!(), $lvl, $message));
-    ($lvl:expr, $format:expr, $($arg:tt)+) => ($crate::log_once!(target: module_path!(), $lvl, $format, $($arg)+));
+
+    // log_once!(Level::Info, "Some {}", "logging")
+    ($lvl:expr, $($arg:tt)+) => ($crate::log_once!(target: module_path!(), $lvl,  $($arg)+));
 }
 
 /// Logs a message once at the error level.
@@ -214,13 +223,15 @@ macro_rules! trace_once {
 
 #[cfg(test)]
 mod tests {
+    use log::{LevelFilter, Log, Metadata, Record};
     use std::cell::Cell;
     use std::sync::Once;
-    use log::{Log, Record, Metadata, LevelFilter};
 
     struct SimpleLogger;
     impl Log for SimpleLogger {
-        fn enabled(&self, _: &Metadata) -> bool {true}
+        fn enabled(&self, _: &Metadata) -> bool {
+            true
+        }
         fn log(&self, _: &Record) {}
         fn flush(&self) {}
     }
@@ -231,8 +242,8 @@ mod tests {
     fn called_once() {
         static START: Once = Once::new();
         START.call_once(|| {
-            ::log::set_logger(&LOGGER).expect("Could not set the logger");
-            ::log::set_max_level(LevelFilter::Trace);
+            log::set_logger(&LOGGER).expect("Could not set the logger");
+            log::set_max_level(LevelFilter::Trace);
         });
 
         let counter = Cell::new(0);

tests/captured-identifiers-format-strings.rs

@@ -0,0 +1,33 @@
+//! Test that we can support capture identifiers in format strings introduced in Rust 1.58.0.
+//! See https://blog.rust-lang.org/2022/01/13/Rust-1.58.0.html#captured-identifiers-in-format-strings
+
+mod logger;
+
+#[test]
+fn info() {
+    logger::init();
+
+    let value = "FOO";
+
+    for _ in 0..2 {
+        log::info!("This is logged twice {value}!");
+    }
+
+    for _ in 0..2 {
+        log_once::info_once!("This is only logged once {value}!");
+    }
+
+    for i in 0..2 {
+        log_once::info_once!("This will be logged twice {i}!");
+    }
+
+    let data = logger::logged_data();
+    let expected = "\
+This is logged twice FOO!
+This is logged twice FOO!
+This is only logged once FOO!
+This will be logged twice 0!
+This will be logged twice 1!
+";
+    assert_eq!(data, expected);
+}

tests/debug.rs

@@ -21,8 +21,8 @@ fn debug() {
     }
 
     let data = logger::logged_data();
-    let expected =
-"Here 42!
+    let expected = "\
+Here 42!
 Here 42!
 Here 42!
 Here 42!

tests/error.rs

@@ -21,8 +21,8 @@ fn error() {
     }
 
     let data = logger::logged_data();
-    let expected =
-"Here 42!
+    let expected = "\
+Here 42!
 Here 42!
 Here 42!
 Here 42!

tests/info.rs

@@ -21,8 +21,8 @@ fn info() {
     }
 
     let data = logger::logged_data();
-    let expected =
-"Here 42!
+    let expected = "\
+Here 42!
 Here 42!
 Here 42!
 Here 42!

tests/logger/mod.rs

@@ -1,8 +1,8 @@
-use log::{Record, LevelFilter, Metadata};
-use std::sync::{Mutex, Once};
+use log::{LevelFilter, Metadata, Record};
 use std::fmt::Write;
+use std::sync::{Mutex, Once};
 
-lazy_static::lazy_static!{
+lazy_static::lazy_static! {
     static ref LOGGED_DATA: Mutex<String> = Mutex::new(String::new());
 }
 
@@ -33,5 +33,8 @@ pub fn init() {
 }
 
 pub fn logged_data() -> String {
-    LOGGED_DATA.lock().expect("Mutex has been poisonned").clone()
+    LOGGED_DATA
+        .lock()
+        .expect("Mutex has been poisonned")
+        .clone()
 }

tests/trace.rs

@@ -21,8 +21,8 @@ fn trace() {
     }
 
     let data = logger::logged_data();
-    let expected =
-"Here 42!
+    let expected = "\
+Here 42!
 Here 42!
 Here 42!
 Here 42!

tests/warn.rs

@@ -21,8 +21,8 @@ fn warn() {
     }
 
     let data = logger::logged_data();
-    let expected =
-"Here 42!
+    let expected = "\
+Here 42!
 Here 42!
 Here 42!
 Here 42!