Log inner errors when chained within a user facing error

Author: jtgeibel

src/controllers.rs

@@ -8,6 +8,8 @@ mod frontend_prelude {
     pub use crate::util::errors::{bad_request, server_error};
 }
 
+pub(crate) use prelude::RequestUtils;
+
 mod prelude {
     pub use super::helpers::ok_true;
     pub use diesel::prelude::*;

src/middleware/log_request.rs

@@ -58,6 +58,16 @@ pub fn add_custom_metadata<V: Display>(req: &mut dyn Request, key: &'static str,
     }
 }
 
+#[cfg(test)]
+pub(crate) fn get_log_message(req: &dyn Request, key: &'static str) -> String {
+    for (k, v) in &req.extensions().find::<CustomMetadata>().unwrap().entries {
+        if key == *k {
+            return v.clone();
+        }
+    }
+    String::new()
+}
+
 struct RequestLine<'r> {
     req: &'r dyn Request,
     res: &'r Result<Response>,

src/router.rs

@@ -143,10 +143,15 @@ impl Handler for C {
         let C(f) = *self;
         match f(req) {
             Ok(resp) => Ok(resp),
-            Err(e) => match e.response() {
-                Some(response) => Ok(response),
-                None => Err(std_error(e)),
-            },
+            Err(e) => {
+                if let Some(cause) = e.cause() {
+                    req.log_metadata("cause", cause.to_string())
+                };
+                match e.response() {
+                    Some(response) => Ok(response),
+                    None => Err(std_error(e)),
+                }
+            }
         }
     }
 }
@@ -181,7 +186,9 @@ impl Handler for R404 {
 #[cfg(test)]
 mod tests {
     use super::*;
-    use crate::util::errors::{bad_request, cargo_err, internal, AppError, NotFound, Unauthorized};
+    use crate::util::errors::{
+        bad_request, cargo_err, internal, AppError, ChainError, NotFound, Unauthorized,
+    };
 
     use conduit_test::MockRequest;
     use diesel::result::Error as DieselError;
@@ -219,6 +226,21 @@ mod tests {
             200
         );
 
+        // Inner errors are captured for logging when wrapped by a user facing error
+        let response = C(|_| {
+            Err("-1"
+                .parse::<u8>()
+                .chain_error(|| bad_request("outer user facing error"))
+                .unwrap_err())
+        })
+        .call(&mut req)
+        .unwrap();
+        assert_eq!(response.status.0, 400);
+        assert_eq!(
+            crate::middleware::log_request::get_log_message(&req, "cause"),
+            "invalid digit found in string"
+        );
+
         // All other error types are propogated up the middleware, eventually becoming status 500
         assert!(C(|_| Err(internal(""))).call(&mut req).is_err());
         assert!(

src/util/errors.rs

@@ -77,6 +77,16 @@ pub trait AppError: Send + fmt::Display + fmt::Debug + 'static {
     /// where it is eventually logged and turned into a status 500 response.
     fn response(&self) -> Option<Response>;
 
+    /// The cause of an error response
+    ///
+    /// If present, an error provided to the `LogRequests` middleware.
+    ///
+    /// This is intended for use with the `ChainError` trait, where a user facing
+    /// error may wrap an internal error we still want to log.
+    fn cause(&self) -> Option<&dyn AppError> {
+        None
+    }
+
     fn get_type_id(&self) -> TypeId {
         TypeId::of::<Self>()
     }
@@ -108,6 +118,10 @@ impl AppError for Box<dyn AppError> {
     fn response(&self) -> Option<Response> {
         (**self).response()
     }
+
+    fn cause(&self) -> Option<&dyn AppError> {
+        (**self).cause()
+    }
 }
 
 pub type AppResult<T> = Result<T, Box<dyn AppError>>;
@@ -128,19 +142,6 @@ struct ChainedError<E> {
     cause: Box<dyn AppError>,
 }
 
-impl<T, F> ChainError<T> for F
-where
-    F: FnOnce() -> AppResult<T>,
-{
-    fn chain_error<E, C>(self, callback: C) -> AppResult<T>
-    where
-        E: AppError,
-        C: FnOnce() -> E,
-    {
-        self().chain_error(callback)
-    }
-}
-
 impl<T, E: AppError> ChainError<T> for Result<T, E> {
     fn chain_error<E2, C>(self, callback: C) -> AppResult<T>
     where
@@ -173,6 +174,10 @@ impl<E: AppError> AppError for ChainedError<E> {
     fn response(&self) -> Option<Response> {
         self.error.response()
     }
+
+    fn cause(&self) -> Option<&dyn AppError> {
+        Some(&*self.cause)
+    }
 }
 
 impl<E: AppError> fmt::Display for ChainedError<E> {