Repository: slog-rs/slog (language: rust)

Issue:
Logging std::error::Error
Currently, it's not specified how to log an error type implementing the `Error` trait. The naive implementation would use `%`, but that's not entirely right as the information about source is lost (`Display` is not supposed to write it).

One could write a helper method to iterate over sources and write them separated with `: `. This works but the structural information is lost. I believe that error types are something one would very much desire to log (at least that's what I do), so it'd be nice to provide a better support for it.

I propose to add a new method to the `Serializer` called `emit_error()` that will accept any type implementing `std::error::Error` and by default iterates through sources and writes them separated by `: `.

I also propose adding a new modifier, e.g `#` for the macros that will log an error using this method.


Discussion / hints:
I guess I'm fine with it, but please double check if adding `#` is really, really, really backward compat.

Fix patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index b96a99976..5080d8e30 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -8,6 +8,8 @@ and this project adheres to [Semantic Versioning](http://semver.org/).
 
 * Add #% for alternate display of the value part
 * Implement `Eq` for dynamic `Key`s
+* Add `emit_error` to `Serializer`, `#` for serializing foreign errors, and
+  `impl Value for std::io::Error`
 
 ## 2.6.0 - 2019-10-28
 
diff --git a/src/lib.rs b/src/lib.rs
index d29170908..904589ef1 100644
--- a/src/lib.rs
+++ b/src/lib.rs
@@ -419,6 +419,9 @@ macro_rules! kv(
     (@ $args_ready:expr; $k:expr => #?$v:expr, $($args:tt)* ) => {
         kv!(@ ($crate::SingleKV::from(($k, __slog_builtin!(@format_args "{:#?}", $v))), $args_ready); $($args)* )
     };
+    (@ $args_ready:expr; $k:expr => #$v:expr) => {
+        kv!(@ ($crate::SingleKV::from(($k, $crate::ErrorValue($v))), $args_ready); )
+    };
     (@ $args_ready:expr; $k:expr => $v:expr) => {
         kv!(@ ($crate::SingleKV::from(($k, $v)), $args_ready); )
     };
@@ -2706,6 +2709,23 @@ pub trait Serializer {
     fn emit_serde(&mut self, key: Key, value: &SerdeValue) -> Result {
         value.serialize_fallback(key, &mut SerializerForward(self))
     }
+
+    /// Emit a type implementing `std::error::Error`
+    ///
+    /// Error values are a bit special as their `Display` implementation doesn't show full
+    /// information about the type but must be retrieved using `source()`. This can be used
+    /// for formatting sources of errors differntly.
+    ///
+    /// The default implementation of this method formats the sources separated with `: `.
+    /// Serializers are encouraged to take advantage of the type information and format it as
+    /// appropriate.
+    ///
+    /// This method is only available in `std` because the `Error` trait is not available
+    /// without `std`.
+    #[cfg(feature = "std")]
+    fn emit_error(&mut self, key: Key, error: &(std::error::Error + 'static)) -> Result {
+        self.emit_arguments(key, &format_args!("{}", ErrorAsFmt(error)))
+    }
 }
 
 /// Serializer to closure adapter.
@@ -2723,6 +2743,30 @@ where
         (self.0)(key, *val)
     }
 }
+
+/// A helper for formatting std::error::Error types by joining sources with `: `
+///
+/// This avoids allocation in the default implementation of `Serializer::emit_error()`.
+/// This is only enabled with `std` as the trait is only available there.
+#[cfg(feature = "std")]
+struct ErrorAsFmt<'a>(pub &'a (std::error::Error + 'static));
+
+#[cfg(feature = "std")]
+impl<'a> fmt::Display for ErrorAsFmt<'a> {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        // For backwards compatibility
+        // This is fine because we don't need downcasting
+        #![allow(deprecated)]
+        write!(f, "{}", self.0)?;
+        let mut error = self.0.cause();
+        while let Some(source) = error {
+            write!(f, ": {}", source)?;
+            error = source.cause();
+        }
+        Ok(())
+    }
+}
+
 // }}}
 
 // {{{ serde
@@ -2980,6 +3024,18 @@ impl Value for std::net::SocketAddr {
     }
 }
 
+#[cfg(feature = "std")]
+impl Value for std::io::Error {
+    fn serialize(
+        &self,
+        _record: &Record,
+        key: Key,
+        serializer: &mut Serializer,
+    ) -> Result {
+        serializer.emit_error(key, self)
+    }
+}
+
 /// Explicit lazy-closure `Value`
 pub struct FnValue<V: Value, F>(pub F)
 where
@@ -3099,6 +3155,33 @@ where
         (self.0)(record, ser)
     }
 }
+
+/// A wrapper struct for serializing errors
+///
+/// This struct can be used to wrap types that don't implement `slog::Value` but
+/// do implement `std::error::Error` so that they can be logged.
+/// This is usually not used directly but using `#error` in the macros.
+///
+/// This struct is only available in `std` because the `Error` trait is not available
+/// without `std`.
+#[cfg(feature = "std")]
+pub struct ErrorValue<E: std::error::Error>(pub E);
+
+#[cfg(feature = "std")]
+impl<E> Value for ErrorValue<E>
+where
+    E: 'static + std::error::Error,
+{
+    fn serialize(
+        &self,
+        _record: &Record,
+        key: Key,
+        serializer: &mut Serializer,
+    ) -> Result {
+        serializer.emit_error(key, &self.0)
+    }
+}
+
 // }}}
 
 // {{{ KV


Test patch:
diff --git a/src/tests.rs b/src/tests.rs
index 0e2612aec..95c4c3822 100644
--- a/src/tests.rs
+++ b/src/tests.rs
@@ -20,6 +20,66 @@ mod std_only {
     use super::super::*;
     use std;
 
+    #[derive(Clone)]
+    struct CheckError;
+
+    impl Drain for CheckError {
+        type Ok = ();
+        type Err = Never;
+        fn log(
+            &self,
+            record: &Record,
+            values: &OwnedKVList,
+        ) -> std::result::Result<Self::Ok, Self::Err> {
+            struct ErrorSerializer(String);
+
+            impl Serializer for ErrorSerializer {
+                fn emit_arguments(&mut self, key: Key, val: &fmt::Arguments) -> Result {
+                    use core::fmt::Write;
+
+                    assert!(key == "error");
+                    self.0.write_fmt(*val).unwrap();
+                    Ok(())
+                }
+            }
+
+            let mut serializer = ErrorSerializer(String::new());
+            values.serialize(record, &mut serializer).unwrap();
+            assert_eq!(
+                serializer.0,
+                format!("{}", record.msg())
+            );
+            Ok(())
+        }
+    }
+
+    #[derive(Debug)]
+    struct TestError<E=std::string::ParseError>(&'static str, Option<E>);
+
+    impl TestError {
+        fn new(message: &'static str) -> Self {
+            TestError(message, None)
+        }
+    }
+
+    impl<E> fmt::Display for TestError<E> {
+        fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+            write!(f, "{}", self.0)
+        }
+    }
+
+    impl<E: std::error::Error + 'static> std::error::Error for TestError<E> {
+        #[allow(deprecated)]
+        fn cause(&self) -> Option<&std::error::Error> {
+            self.1.as_ref().map(|error| error as _)
+        }
+
+        #[allow(deprecated)]
+        fn description(&self) -> &str {
+            "test error"
+        }
+    }
+
     #[test]
     fn logger_fmt_debug_sanity() {
         let root = Logger::root(Discard, o!("a" => "aa"));
@@ -59,6 +119,32 @@ mod std_only {
         let log = Logger::root(log, o!("d1" => "dd", "d2" => "dd"));
         info!(log, "(d2, d1, c, b2, b1, a)");
     }
+
+    #[test]
+    fn error_fmt_no_source() {
+        let logger = Logger::root(CheckError, o!("error" => #TestError::new("foo")));
+        info!(logger, "foo");
+    }
+
+    #[test]
+    fn error_fmt_single_source() {
+        let logger = Logger::root(CheckError, o!("error" => #TestError("foo", Some(TestError::new("bar")))));
+        info!(logger, "foo: bar");
+    }
+
+    #[test]
+    fn error_fmt_two_sources() {
+        let logger = Logger::root(CheckError, o!("error" => #TestError("foo", Some(TestError("bar", Some(TestError::new("baz")))))));
+        info!(logger, "foo: bar: baz");
+    }
+
+    #[test]
+    fn ioerror_impls_value() {
+        let logger = Logger::root(Discard, o!());
+        info!(logger, "not found"; "error" => std::io::Error::from(std::io::ErrorKind::NotFound));
+        // compiles?
+        info!(logger, "not found"; "error" => #std::io::Error::from(std::io::ErrorKind::NotFound));
+    }
 }
 
 #[test]
@@ -205,6 +291,7 @@ fn expressions_fmt() {
     info!(log, "message"; "f" => %f, "d" => ?d);
 }
 
+#[cfg(feature = "std")]
 #[test]
 fn display_and_alternate_display() {
     use core::fmt;
@@ -232,20 +319,22 @@ fn display_and_alternate_display() {
         fn log(&self, record: &Record, values: &OwnedKVList) -> Result<(), Never> {
             let mut checked_n = false;
             let mut checked_a = false;
-            let mut serializer = AsFmtSerializer(|key, fmt_args| {
-                if key == "n" {
-                    assert_eq!(format!("{}", fmt_args), "normal");
-                    checked_n = true;
-                } else if key == "a" {
-                    assert_eq!(format!("{}", fmt_args), "alternate");
-                    checked_a = true;
-                } else {
-                    panic!("Unexpected key: {}", key);
-                }
-                Ok(())
-            });
-
-            record.kv.serialize(record, &mut serializer).unwrap();
+            {
+                let mut serializer = AsFmtSerializer(|key, fmt_args| {
+                    if key == "n" {
+                        assert_eq!(format!("{}", fmt_args), "normal");
+                        checked_n = true;
+                    } else if key == "a" {
+                        assert_eq!(format!("{}", fmt_args), "alternate");
+                        checked_a = true;
+                    } else {
+                        panic!("Unexpected key: {}", key);
+                    }
+                    Ok(())
+                });
+
+                record.kv.serialize(record, &mut serializer).unwrap();
+            }
 
             assert!(checked_n, "Expected the normal formatter to be used");
             assert!(checked_a, "Expected the alternate formatter to be used");
@@ -321,6 +410,7 @@ fn test_never_type_clone() {
     // Always pass if we compiled
 }
 
+#[cfg(feature = "std")]
 #[test]
 fn can_hash_keys() {
     use std::collections::HashSet;