Edit access logs ASCII format, put logs-cache under feature

Signed-off-by: Eloi DEMOLIS <eloi.demolis@clever-cloud.com>

bin/src/command/server.rs

@@ -1,6 +1,6 @@
 use std::{
     collections::{HashMap, HashSet},
-    fmt::Debug,
+    fmt::{self, Debug},
     io::Error as IoError,
     ops::{Deref, DerefMut},
     os::fd::{AsRawFd, FromRawFd},
@@ -858,8 +858,8 @@ impl Server {
     }
 }
 
-impl std::fmt::Debug for Server {
-    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+impl Debug for Server {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
         f.debug_struct("Server")
             .field("config", &self.config)
             .field("event_subscribers", &self.event_subscribers)

command/Cargo.toml

@@ -53,6 +53,7 @@ x509-parser = "^0.16.0"
 unstable = []
 logs-debug = []
 logs-trace = []
+logs-cache = []
 
 [badges]
 travis-ci = { repository = "sozu-proxy/sozu" }

command/src/logging/access_logs.rs

@@ -31,7 +31,7 @@ impl<T> DuplicateOwnership for &T {
 impl<'a, T> DuplicateOwnership for Option<&'a T>
 where
     T: ?Sized,
-    &'a T: DuplicateOwnership + 'a,
+    &'a T: DuplicateOwnership,
 {
     type Target = Option<<&'a T as DuplicateOwnership>::Target>;
     unsafe fn duplicate(self) -> Self::Target {
@@ -133,48 +133,50 @@ impl RequestRecord<'_> {
     /// Converts the RequestRecord in its protobuf representation.
     /// Prost needs ownership over all the fields but we don't want to take it from the user
     /// or clone them, so we use the unsafe DuplicateOwnership.
-    pub unsafe fn into_binary_access_log(self) -> ManuallyDrop<ProtobufAccessLog> {
-        let endpoint = match self.endpoint {
-            EndpointRecord::Http {
-                method,
-                authority,
-                path,
-                status,
-                reason,
-            } => protobuf_endpoint::Inner::Http(HttpEndpoint {
-                method: method.duplicate(),
-                authority: authority.duplicate(),
-                path: path.duplicate(),
-                status: status.map(|s| s as u32),
-                reason: reason.duplicate(),
-            }),
-            EndpointRecord::Tcp => protobuf_endpoint::Inner::Tcp(TcpEndpoint {}),
-        };
+    pub fn into_binary_access_log(self) -> ManuallyDrop<ProtobufAccessLog> {
+        unsafe {
+            let endpoint = match self.endpoint {
+                EndpointRecord::Http {
+                    method,
+                    authority,
+                    path,
+                    status,
+                    reason,
+                } => protobuf_endpoint::Inner::Http(HttpEndpoint {
+                    method: method.duplicate(),
+                    authority: authority.duplicate(),
+                    path: path.duplicate(),
+                    status: status.map(|s| s as u32),
+                    reason: reason.duplicate(),
+                }),
+                EndpointRecord::Tcp => protobuf_endpoint::Inner::Tcp(TcpEndpoint {}),
+            };
 
-        ManuallyDrop::new(ProtobufAccessLog {
-            backend_address: self.backend_address.map(Into::into),
-            backend_id: self.context.backend_id.duplicate(),
-            bytes_in: self.bytes_in as u64,
-            bytes_out: self.bytes_out as u64,
-            client_rtt: self.client_rtt.map(|t| t.whole_microseconds() as u64),
-            cluster_id: self.context.cluster_id.duplicate(),
-            endpoint: ProtobufEndpoint {
-                inner: Some(endpoint),
-            },
-            message: self.message.duplicate(),
-            protocol: self.protocol.duplicate(),
-            request_id: self.context.request_id.into(),
-            response_time: self.response_time.whole_microseconds() as u64,
-            server_rtt: self.server_rtt.map(|t| t.whole_microseconds() as u64),
-            service_time: self.service_time.whole_microseconds() as u64,
-            session_address: self.session_address.map(Into::into),
-            tags: self
-                .tags
-                .map(|tags| tags.tags.duplicate())
-                .unwrap_or_default(),
-            user_agent: self.user_agent.duplicate(),
-            tag: self.tag.duplicate(),
-            time: self.precise_time.into(),
-        })
+            ManuallyDrop::new(ProtobufAccessLog {
+                backend_address: self.backend_address.map(Into::into),
+                backend_id: self.context.backend_id.duplicate(),
+                bytes_in: self.bytes_in as u64,
+                bytes_out: self.bytes_out as u64,
+                client_rtt: self.client_rtt.map(|t| t.whole_microseconds() as u64),
+                cluster_id: self.context.cluster_id.duplicate(),
+                endpoint: ProtobufEndpoint {
+                    inner: Some(endpoint),
+                },
+                message: self.message.duplicate(),
+                protocol: self.protocol.duplicate(),
+                request_id: self.context.request_id.into(),
+                response_time: self.response_time.whole_microseconds() as u64,
+                server_rtt: self.server_rtt.map(|t| t.whole_microseconds() as u64),
+                service_time: self.service_time.whole_microseconds() as u64,
+                session_address: self.session_address.map(Into::into),
+                tags: self
+                    .tags
+                    .map(|tags| tags.tags.duplicate())
+                    .unwrap_or_default(),
+                user_agent: self.user_agent.duplicate(),
+                tag: self.tag.duplicate(),
+                time: self.precise_time.into(),
+            })
+        }
     }
 }

command/src/logging/display.rs

@@ -47,7 +47,7 @@ impl AsRef<str> for LoggerBackend {
 }
 
 impl fmt::Display for Rfc3339Time {
-    fn fmt(&self, f: &mut std::fmt::Formatter) -> Result<(), std::fmt::Error> {
+    fn fmt(&self, f: &mut fmt::Formatter) -> Result<(), fmt::Error> {
         let t = self.inner;
         write!(
             f,
@@ -100,7 +100,7 @@ impl fmt::Display for LogDuration {
 }
 
 impl fmt::Display for LogContext<'_> {
-    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
         write!(
             f,
             "[{} {} {}]",
@@ -160,12 +160,8 @@ impl<'a> fmt::Display for FullTags<'a> {
 }
 
 fn prepare_user_agent(user_agent: &str) -> String {
-    let mut user_agent = user_agent.replace(' ', "_");
-    let mut ua_bytes = std::mem::take(&mut user_agent).into_bytes();
-    if let Some(last) = ua_bytes.last_mut() {
-        if *last == b',' {
-            *last = b'!'
-        }
-    }
-    unsafe { String::from_utf8_unchecked(ua_bytes) }
+    user_agent
+        .replace(' ', "_")
+        .replace('[', "{")
+        .replace(']', "}")
 }

command/src/logging/logs.rs

@@ -230,7 +230,7 @@ impl InnerLogger {
 
         let io_result = match self.access_format {
             AccessLogFormat::Protobuf => {
-                let binary_log = unsafe { log.into_binary_access_log() };
+                let binary_log = log.into_binary_access_log();
                 let log_length = binary_log.encoded_len();
                 let total_length = log_length + encoded_len_varint(log_length as u64);
                 self.buffer.clear();
@@ -269,11 +269,11 @@ impl InnerLogger {
                     log.tag,
                 ],
                 standard: {
-                    formats: ["{} {}->{} {}/{}/{}/{} {}->{} [{}] {} {}{}\n"],
+                    formats: ["{} {} {} {}/{}/{}/{} {} {} [{}] {} {}{}\n"],
                     args: [
                         log.context,
-                        log.session_address.as_string_or("X"),
-                        log.backend_address.as_string_or("X"),
+                        log.session_address.as_string_or("-"),
+                        log.backend_address.as_string_or("-"),
                         LogDuration(Some(log.response_time)),
                         LogDuration(Some(log.service_time)),
                         LogDuration(log.client_rtt),
@@ -287,7 +287,7 @@ impl InnerLogger {
                     ]
                 },
                 colored: {
-                    formats: ["\x1b[;1m{}\x1b[m {}->{} {}/{}/{}/{} {}->{} \x1b[2m[{}] \x1b[;1m{} {:#}\x1b[m{}\n"],
+                    formats: ["\x1b[;1m{}\x1b[m {} {} {}/{}/{}/{} {} {} \x1b[2m[{}] \x1b[;1m{} {:#}\x1b[m{}\n"],
                     args: @,
                 }
             },
@@ -794,16 +794,38 @@ impl LogLineCachedState {
     }
 }
 
+#[macro_export]
+macro_rules! log_enabled {
+    ($logger:expr, $lvl:expr) => {{
+        let logger = $logger.borrow_mut();
+        let enable = if cfg!(feature = "logs-cache") {
+            static mut LOG_LINE_CACHED_STATE: $crate::logging::LogLineCachedState =
+                $crate::logging::LogLineCachedState::new();
+            logger.cached_enabled(
+                unsafe { &mut LOG_LINE_CACHED_STATE },
+                $crate::logging::Metadata {
+                    level: $lvl,
+                    target: module_path!(),
+                },
+            )
+        } else {
+            logger.enabled($crate::logging::Metadata {
+                level: $lvl,
+                target: module_path!(),
+            })
+        };
+        if !enable {
+            return;
+        }
+        logger
+    }};
+}
+
 #[macro_export]
 macro_rules! log {
     ($lvl:expr, $format:expr $(, $args:expr)*) => {{
-        static mut LOG_LINE_CACHED_STATE: $crate::logging::LogLineCachedState = $crate::logging::LogLineCachedState::new();
         $crate::logging::LOGGER.with(|logger| {
-            let mut logger = logger.borrow_mut();
-            if !logger.cached_enabled(
-                unsafe { &mut LOG_LINE_CACHED_STATE },
-                $crate::logging::Metadata { level: $lvl, target: module_path!() }
-            ) { return; }
+            let mut logger = $crate::log_enabled!(logger, $lvl);
             let (pid, tag, inner) = logger.split();
             let (now, precise_time) = $crate::logging::now();
 
@@ -824,13 +846,8 @@ macro_rules! log {
 #[macro_export]
 macro_rules! log_access {
     ($lvl:expr, $($request_record_fields:tt)*) => {{
-        static mut LOG_LINE_CACHED_STATE: $crate::logging::LogLineCachedState = $crate::logging::LogLineCachedState::new();
         $crate::logging::LOGGER.with(|logger| {
-            let mut logger = logger.borrow_mut();
-            if !logger.cached_enabled(
-                unsafe { &mut LOG_LINE_CACHED_STATE },
-                $crate::logging::Metadata { level: $lvl, target: module_path!() }
-            ) { return; }
+            let mut logger = $crate::log_enabled!(logger, $lvl);
             let (pid, tag, inner) = logger.split();
             let (now, precise_time) = $crate::logging::now();
 

command/src/response.rs

@@ -130,7 +130,7 @@ pub fn is_default_path_rule(p: &PathRule) -> bool {
     PathRuleKind::try_from(p.kind) == Ok(PathRuleKind::Prefix) && p.value.is_empty()
 }
 
-impl std::fmt::Display for PathRule {
+impl fmt::Display for PathRule {
     fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
         match PathRuleKind::try_from(self.kind) {
             Ok(PathRuleKind::Prefix) => write!(f, "prefix '{}'", self.value),

lib/src/tls.rs

@@ -7,7 +7,7 @@ use std::{
     borrow::ToOwned,
     collections::{HashMap, HashSet},
     convert::From,
-    fmt::Debug,
+    fmt,
     io::BufReader,
     str::FromStr,
     sync::{Arc, Mutex},
@@ -390,7 +390,7 @@ impl ResolvesServerCert for MutexCertificateResolver {
     }
 }
 
-impl Debug for MutexCertificateResolver {
+impl fmt::Debug for MutexCertificateResolver {
     fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
         f.write_str("MutexWrappedCertificateResolver")
     }