Initial implementation of adding key value pairs

Cargo.toml

@@ -21,6 +21,10 @@ features = ["std", "serde"]
 name = "filters"
 harness = false
 
+[[test]]
+name = "kv"
+harness = false
+
 [features]
 max_level_off   = []
 max_level_error = []

src/lib.rs

@@ -659,6 +659,32 @@ impl LevelFilter {
     }
 }
 
+/// The trait to represent key value pairs.
+pub trait KeyValue {
+    /// The key.
+    fn key(&self) -> &fmt::Display;
+    /// The value.
+    fn value(&self) -> &fmt::Display;
+}
+
+/// Implementation of the `KeyValue` trait used by the `log!` macro.
+#[allow(missing_debug_implementations)]
+#[doc(hidden)]
+pub struct KV<'a> {
+    pub key: &'static str,
+    pub value: &'a fmt::Display,
+}
+
+impl<'a> KeyValue for KV<'a> {
+    fn key(&self) -> &fmt::Display {
+        &self.key
+    }
+
+    fn value(&self) -> &fmt::Display {
+        &self.value
+    }
+}
+
 /// The "payload" of a log message.
 ///
 /// # Use
@@ -705,10 +731,11 @@ impl LevelFilter {
 /// [`log!`]: macro.log.html
 /// [`level()`]: struct.Record.html#method.level
 /// [`target()`]: struct.Record.html#method.target
-#[derive(Clone, Debug)]
+#[derive(Clone)]
 pub struct Record<'a> {
     metadata: Metadata<'a>,
     args: fmt::Arguments<'a>,
+    kvs: &'a [&'a KeyValue],
     module_path: Option<&'a str>,
     file: Option<&'a str>,
     line: Option<u32>,
@@ -727,6 +754,12 @@ impl<'a> Record<'a> {
         &self.args
     }
 
+    /// Supplied key value pairs.
+    #[inline]
+    pub fn kvs(&self) -> &'a [&'a KeyValue] {
+        &self.kvs
+    }
+
     /// Metadata about the log directive.
     #[inline]
     pub fn metadata(&self) -> &Metadata<'a> {
@@ -764,6 +797,32 @@ impl<'a> Record<'a> {
     }
 }
 
+/// Helper struct to allow debug printing of `KeyValue` pairs.
+struct KeyValueDebug<'a>(&'a [&'a KeyValue]);
+
+impl<'a> fmt::Debug for KeyValueDebug<'a> {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        write!(f, "[ ")?;
+        for kv in self.0 {
+            write!(f, "{} = {}, ", kv.key(), kv.value())?;
+        }
+        write!(f, "]")
+    }
+}
+
+impl<'a> fmt::Debug for Record<'a> {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        f.debug_struct("Record")
+            .field("metadata", &self.metadata)
+            .field("args", &self.args)
+            .field("kvs", &KeyValueDebug(&self.kvs))
+            .field("module_path", &self.module_path)
+            .field("file", &self.file)
+            .field("line", &self.line)
+            .finish()
+    }
+}
+
 /// Builder for [`Record`](struct.Record.html).
 ///
 /// Typically should only be used by log library creators or for testing and "shim loggers".
@@ -827,6 +886,7 @@ impl<'a> RecordBuilder<'a> {
         RecordBuilder {
             record: Record {
                 args: format_args!(""),
+                kvs: &[],
                 metadata: Metadata::builder().build(),
                 module_path: None,
                 file: None,
@@ -842,6 +902,13 @@ impl<'a> RecordBuilder<'a> {
         self
     }
 
+    /// Set [`kvs`](struct.Record.html#method.kvs).
+    #[inline]
+    pub fn kvs(&mut self, kvs: &'a [&'a KeyValue]) -> &mut RecordBuilder<'a> {
+        self.record.kvs = kvs;
+        self
+    }
+
     /// Set [`metadata`](struct.Record.html#method.metadata). Construct a `Metadata` object with [`MetadataBuilder`](struct.MetadataBuilder.html).
     #[inline]
     pub fn metadata(&mut self, metadata: Metadata<'a>) -> &mut RecordBuilder<'a> {
@@ -1220,12 +1287,14 @@ pub fn logger() -> &'static Log {
 #[doc(hidden)]
 pub fn __private_api_log(
     args: fmt::Arguments,
+    kvs: &[&KeyValue],
     level: Level,
     &(target, module_path, file, line): &(&str, &str, &str, u32),
 ) {
     logger().log(
         &Record::builder()
             .args(args)
+            .kvs(kvs)
             .level(level)
             .target(target)
             .module_path(Some(module_path))

src/macros.rs

@@ -23,25 +23,32 @@
 /// # fn main() {
 /// let data = (42, "Forty-two");
 /// let private_data = "private";
+/// let user = ("Bob", 123);
 ///
 /// log!(Level::Error, "Received errors: {}, {}", data.0, data.1);
 /// log!(target: "app_events", Level::Warn, "App warning: {}, {}, {}",
-///     data.0, data.1, private_data);
+///     data.0, data.1, private_data; user_name = user.0, user_id = user.1);
 /// # }
 /// ```
 #[macro_export]
 macro_rules! log {
-    (target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
+    (target: $target:expr, $lvl:expr, $($arg:expr),+; $($k:ident = $v:expr),*) => ({
         let lvl = $lvl;
         if lvl <= $crate::STATIC_MAX_LEVEL && lvl <= $crate::max_level() {
             $crate::__private_api_log(
-                format_args!($($arg)+),
+                format_args!($($arg),+),
+                &[$(&$crate::KV { key: stringify!($k), value: &$v }),*],
                 lvl,
                 &($target, module_path!(), file!(), line!()),
             );
         }
     });
-    ($lvl:expr, $($arg:tt)+) => (log!(target: module_path!(), $lvl, $($arg)+))
+    // No key value pairs.
+    (target: $target:expr, $lvl:expr, $($arg:expr),+) => (log!(target: $target, $lvl, $($arg),+; ));
+    // No target.
+    ($lvl:expr, $($arg:expr),+; $($k:ident = $v:expr),*) => (log!(target: module_path!(), $lvl, $($arg),+; $($k = $v),*));
+    // No target or key value pairs.
+    ($lvl:expr, $($arg:expr),+) => (log!($lvl, $($arg),+; ));
 }
 
 /// Logs a message at the error level.
@@ -60,11 +67,11 @@ macro_rules! log {
 /// ```
 #[macro_export]
 macro_rules! error {
-    (target: $target:expr, $($arg:tt)*) => (
-        log!(target: $target, $crate::Level::Error, $($arg)*);
+    (target: $target:expr, $($arg:expr),+) => (
+        log!(target: $target, $crate::Level::Error, $($arg),+);
     );
-    ($($arg:tt)*) => (
-        log!($crate::Level::Error, $($arg)*);
+    ($($arg:expr),+) => (
+        log!($crate::Level::Error, $($arg),+);
     )
 }
 
@@ -84,11 +91,11 @@ macro_rules! error {
 /// ```
 #[macro_export]
 macro_rules! warn {
-    (target: $target:expr, $($arg:tt)*) => (
-        log!(target: $target, $crate::Level::Warn, $($arg)*);
+    (target: $target:expr, $($arg:expr),+) => (
+        log!(target: $target, $crate::Level::Warn, $($arg),+);
     );
-    ($($arg:tt)*) => (
-        log!($crate::Level::Warn, $($arg)*);
+    ($($arg:expr),+) => (
+        log!($crate::Level::Warn, $($arg),+);
     )
 }
 
@@ -110,11 +117,11 @@ macro_rules! warn {
 /// ```
 #[macro_export]
 macro_rules! info {
-    (target: $target:expr, $($arg:tt)*) => (
-        log!(target: $target, $crate::Level::Info, $($arg)*);
+    (target: $target:expr, $($arg:expr),+) => (
+        log!(target: $target, $crate::Level::Info, $($arg),+);
     );
-    ($($arg:tt)*) => (
-        log!($crate::Level::Info, $($arg)*);
+    ($($arg:expr),+) => (
+        log!($crate::Level::Info, $($arg),+);
     )
 }
 
@@ -135,11 +142,11 @@ macro_rules! info {
 /// ```
 #[macro_export]
 macro_rules! debug {
-    (target: $target:expr, $($arg:tt)*) => (
-        log!(target: $target, $crate::Level::Debug, $($arg)*);
+    (target: $target:expr, $($arg:expr),+) => (
+        log!(target: $target, $crate::Level::Debug, $($arg),+);
     );
-    ($($arg:tt)*) => (
-        log!($crate::Level::Debug, $($arg)*);
+    ($($arg:expr),+) => (
+        log!($crate::Level::Debug, $($arg),+);
     )
 }
 
@@ -162,11 +169,11 @@ macro_rules! debug {
 /// ```
 #[macro_export]
 macro_rules! trace {
-    (target: $target:expr, $($arg:tt)*) => (
-        log!(target: $target, $crate::Level::Trace, $($arg)*);
+    (target: $target:expr, $($arg:expr),+) => (
+        log!(target: $target, $crate::Level::Trace, $($arg),+);
     );
-    ($($arg:tt)*) => (
-        log!($crate::Level::Trace, $($arg)*);
+    ($($arg:expr),+) => (
+        log!($crate::Level::Trace, $($arg),+);
     )
 }
 

tests/kv.rs

@@ -0,0 +1,71 @@
+#[macro_use]
+extern crate log;
+
+use std::io::Write;
+use std::sync::{Arc, Mutex};
+use log::{Level, LevelFilter, Log, Record, Metadata};
+
+#[cfg(feature = "std")]
+use log::set_boxed_logger;
+
+#[cfg(not(feature = "std"))]
+fn set_boxed_logger(logger: Box<Log>) -> Result<(), log::SetLoggerError> {
+    log::set_logger(unsafe { &*Box::into_raw(logger) })
+}
+
+struct Logger {
+    buf: Arc<Mutex<Vec<u8>>>,
+}
+
+impl Log for Logger {
+    fn enabled(&self, _: &Metadata) -> bool {
+        true
+    }
+
+    fn log(&self, record: &Record) {
+        let mut buf = self.buf.lock().unwrap();
+        buf.write_fmt(*record.args()).unwrap();
+        for kv in record.kvs() {
+            write!(buf, " {} = {},", kv.key(), kv.value()).unwrap();
+        }
+        buf.write(b"\n").unwrap();
+    }
+
+    fn flush(&self) {}
+}
+
+fn main() {
+    let buf = Vec::new();
+    let buf = Arc::new(Mutex::new(buf));
+
+    log::set_max_level(LevelFilter::Trace);
+    set_boxed_logger(Box::new(Logger { buf: Arc::clone(&buf) })).unwrap();
+
+    let user = ("Bob", 123);
+
+    // Single message, no key-value pairs.
+    log!(Level::Error, "Simple message");
+    log!(target: "target", Level::Error, "Targeted message");
+    // Message with arguments, no key-value pairs.
+    log!(Level::Error, "Args message: {}, {}", "arg1", 890);
+    log!(target: "target", Level::Error, "Targeted args message: {}, {}", "arg1", 890);
+    // Single message, no arguments.
+    log!(Level::Error, "KV message"; id = user.1, name = user.0);
+    log!(target: "target", Level::Error, "Targeted KV message"; id = 123, key2 = "value2");
+    // Message with arguments, two key-value pairs.
+    log!(Level::Error, "Args KV message: {}, {}", "arg1", 890; id = 123, key2 = "value2");
+    log!(target: "target", Level::Error, "Targeted args KV message: {}, {}", "arg1", 890; id = 123, key2 = "value2");
+
+    let buf = buf.lock().unwrap();
+    let got = String::from_utf8_lossy(&buf);
+    const WANT: &str = "Simple message
+Targeted message
+Args message: arg1, 890
+Targeted args message: arg1, 890
+KV message id = 123, name = Bob,
+Targeted KV message id = 123, key2 = value2,
+Args KV message: arg1, 890 id = 123, key2 = value2,
+Targeted args KV message: arg1, 890 id = 123, key2 = value2,
+";
+    assert_eq!(got, WANT);
+}