From 36c8a1535b5f93b7b01fa477e39c950e621d54f9 Mon Sep 17 00:00:00 2001
From: Justin Geibel <jtgeibel@gmail.com>
Date: Wed, 25 Dec 2019 14:53:34 -0500
Subject: [PATCH 1/2] Consolidate logging into a single `println!()`

In production I observed serveral log lines with only " SLOW REQUEST".
Occasionally another thread will obtain the lock on stdout between our
calls to `print!()`.

This implementation consolidates the entire log line into a single
`println!()` and avoids an allocation unless an error is being logged.
---
 src/middleware/log_request.rs | 28 ++++++++++++++++------------
 1 file changed, 16 insertions(+), 12 deletions(-)

diff --git a/src/middleware/log_request.rs b/src/middleware/log_request.rs
index 2b31527f199..33978af700c 100644
--- a/src/middleware/log_request.rs
+++ b/src/middleware/log_request.rs
@@ -36,11 +36,23 @@ impl Handler for LogRequests {
             .find::<u64>()
             .map_or(String::new(), |l| format!(" metadata_length={}", l));
 
-        print!(
+        let slow_request = if response_time > 1000 {
+            " SLOW REQUEST"
+        } else {
+            ""
+        };
+
+        let error = if let Err(ref e) = res {
+            format!(" error=\"{}\"", e.to_string())
+        } else {
+            String::new()
+        };
+
+        println!(
             "at={level} method={method} path=\"{path}\" \
              request_id={request_id} fwd=\"{ip}\" service={time_ms}ms \
              status={status} user_agent=\"{user_agent}\"\
-             {metadata_length}",
+             {metadata_length}{error}{slow_request}",
             level = level,
             method = req.method(),
             path = FullPath(req),
@@ -50,18 +62,10 @@ impl Handler for LogRequests {
             request_id = request_header(req, "X-Request-Id"),
             status = response_code,
             metadata_length = metadata_length,
+            error = error,
+            slow_request = slow_request,
         );
 
-        if let Err(ref e) = res {
-            print!(" error=\"{}\"", e.to_string());
-        }
-
-        if response_time > 1000 {
-            print!(" SLOW REQUEST");
-        }
-
-        println!();
-
         res
     }
 }

From e8dd7295a102519a2c487b1070a530d2418a9c63 Mon Sep 17 00:00:00 2001
From: Justin Geibel <jtgeibel@gmail.com>
Date: Wed, 25 Dec 2019 15:00:27 -0500
Subject: [PATCH 2/2] Avoid an additional allocation when logging errors

The call to `to_string()` results in an unnecessary allocation.  `Error`
only implements `ToString` through the `Display` trait.  The same
formatting logic is used, but calling `to_string()` causes an additional
heap allocation.
---
 src/middleware/log_request.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/middleware/log_request.rs b/src/middleware/log_request.rs
index 33978af700c..b6097554fe5 100644
--- a/src/middleware/log_request.rs
+++ b/src/middleware/log_request.rs
@@ -43,7 +43,7 @@ impl Handler for LogRequests {
         };
 
         let error = if let Err(ref e) = res {
-            format!(" error=\"{}\"", e.to_string())
+            format!(" error=\"{}\"", e)
         } else {
             String::new()
         };