Auto merge of #2064 - jtgeibel:prod/interlaced-logs, r=carols10cents

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.

r? @smarnach

Author: bors

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)
+        } 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
     }
 }