Use error_access in lib, add log_access to make it easier

Signed-off-by: Eloi DEMOLIS <[email protected]>
sozu-proxy · Feb 21, 2024 · 0ca4d2a · 0ca4d2a
1 parent e07964f
commit 0ca4d2a
Show file tree

Hide file tree

Showing 8 changed files with 55 additions and 58 deletions.
diff --git a/command/src/logging/logs.rs b/command/src/logging/logs.rs
@@ -257,7 +257,7 @@ impl InnerLogger {
                     .map(|_| ())
                 }
             }
-            AccessLogFormat::Ascii => crate::prompt_log! {
+            AccessLogFormat::Ascii => crate::_prompt_log! {
                 logger: |args| log_arguments(args, backend, &mut self.buffer),
                 is_access: true,
                 condition: self.access_colored,
@@ -687,22 +687,15 @@ pub fn target_to_backend(target: &str) -> LoggerBackend {
 }
 
 #[macro_export]
-macro_rules! bind_format_args {
-    (let $args: ident = ($($f:tt)+); $($t:tt)*) => {
-        (|$args| { $($t)* })($($f)+)
-    };
-}
-
-#[macro_export]
-macro_rules! prompt_log {
+macro_rules! _prompt_log {
     {
         logger: $logger:expr,
         is_access: $access:expr,
         condition: $cond:expr,
         prompt: [$($p:tt)*],
         standard: {$($std:tt)*}$(,)?
     } => {
-        $crate::prompt_log!{
+        $crate::_prompt_log!{
             logger: $logger,
             is_access: $access,
             condition: $cond,
@@ -725,7 +718,7 @@ macro_rules! prompt_log {
             args: @$(,)?
         }$(,)?
     } => {
-        $crate::prompt_log!{
+        $crate::_prompt_log!{
             logger: $logger,
             is_access: $access,
             condition: $cond,
@@ -755,14 +748,14 @@ macro_rules! prompt_log {
         }$(,)?
     } => {
         if $cond {
-            $crate::prompt_log!(@bind [$logger, concat!("{} \x1b[2m{} \x1b[;2;1m{} {} \x1b[0;1m{}\x1b[m\t", $($col_fmt)*)] [$now, $precise_time, $pid, $lvl.as_str($access, true), $tag] $($col_args),*)
+            $crate::_prompt_log!(@bind [$logger, concat!("{} \x1b[2m{} \x1b[;2;1m{} {} \x1b[0;1m{}\x1b[m\t", $($col_fmt)*)] [$now, $precise_time, $pid, $lvl.as_str($access, true), $tag] $($col_args),*)
         } else {
-            $crate::prompt_log!(@bind [$logger, concat!("{} {} {} {} {}\t", $($std_fmt)*)] [$now, $precise_time, $pid, $lvl.as_str($access, false), $tag] $($std_args),*)
+            $crate::_prompt_log!(@bind [$logger, concat!("{} {} {} {} {}\t", $($std_fmt)*)] [$now, $precise_time, $pid, $lvl.as_str($access, false), $tag] $($std_args),*)
         }
     };
     (@bind [$logger:expr, $fmt:expr] [$($bindings:expr),*] $arg:expr $(, $args:expr)*) => {{
         let binding = &$arg;
-        $crate::prompt_log!(@bind [$logger, $fmt] [$($bindings),* , binding] $($args),*)
+        $crate::_prompt_log!(@bind [$logger, $fmt] [$($bindings),* , binding] $($args),*)
     }};
     (@bind [$logger:expr, $fmt:expr] [$($bindings:expr),*]) => {
         $logger(format_args!($fmt, $($bindings),*))
@@ -795,7 +788,7 @@ impl LogLineCachedState {
 }
 
 #[macro_export]
-macro_rules! log_enabled {
+macro_rules! _log_enabled {
     ($logger:expr, $lvl:expr) => {{
         let logger = $logger.borrow_mut();
         let enable = if cfg!(feature = "logs-cache") {
@@ -822,14 +815,14 @@ macro_rules! log_enabled {
 }
 
 #[macro_export]
-macro_rules! log {
+macro_rules! _log {
     ($lvl:expr, $format:expr $(, $args:expr)*) => {{
         $crate::logging::LOGGER.with(|logger| {
-            let mut logger = $crate::log_enabled!(logger, $lvl);
+            let mut logger = $crate::_log_enabled!(logger, $lvl);
             let (pid, tag, inner) = logger.split();
             let (now, precise_time) = $crate::logging::now();
 
-            $crate::prompt_log!{
+            $crate::_prompt_log!{
                 logger: |args| inner.log(args),
                 is_access: false,
                 condition: inner.colored,
@@ -844,67 +837,80 @@ macro_rules! log {
 }
 
 #[macro_export]
-macro_rules! log_access {
+macro_rules! _log_access {
     ($lvl:expr, $($request_record_fields:tt)*) => {{
         $crate::logging::LOGGER.with(|logger| {
-            let mut logger = $crate::log_enabled!(logger, $lvl);
+            let mut logger = $crate::_log_enabled!(logger, $lvl);
             let (pid, tag, inner) = logger.split();
             let (now, precise_time) = $crate::logging::now();
 
             inner.log_access(
-                structured_access_log!([$crate::logging::RequestRecord]
+                $crate::_structured_access_log!([$crate::logging::RequestRecord]
                 pid, tag, now, precise_time, level: $lvl, $($request_record_fields)*
             ));
         })
     }};
 }
 
 #[macro_export]
-macro_rules! structured_access_log {
+macro_rules! _structured_access_log {
     ([$($struct_name:tt)+] $($fields:tt)*) => {{
         $($struct_name)+ {$(
             $fields
         )*}
     }};
 }
 
+#[macro_export]
+/// dynamically chose between info_access and error_access
+macro_rules! log_access {
+    ($error:expr, $($request_record_fields:tt)*) => {
+        let lvl = if $error {
+            $crate::logging::LogLevel::Error
+        } else {
+            $crate::logging::LogLevel::Info
+        };
+        _log_access!(lvl, $($request_record_fields)*);
+    };
+}
+
 /// log a failure concerning an HTTP or TCP request
 #[macro_export]
 macro_rules! error_access {
     ($($request_record_fields:tt)*) => {
-        log_access!($crate::logging::LogLevel::Error, $($request_record_fields)*);
+        $crate::_log_access!($crate::logging::LogLevel::Error, $($request_record_fields)*);
     };
 }
 
 /// log the success of an HTTP or TCP request
 #[macro_export]
 macro_rules! info_access {
     ($($request_record_fields:tt)*) => {
-        log_access!($crate::logging::LogLevel::Info, $($request_record_fields)*);
+        $crate::_log_access!($crate::logging::LogLevel::Info, $($request_record_fields)*);
     };
 }
 
 /// log an error with Sōzu's custom log stack
 #[macro_export]
 macro_rules! error {
     ($format:expr $(, $args:expr)* $(,)?) => {
-        log!($crate::logging::LogLevel::Error, $format $(, $args)*)
+        $crate::_log!($crate::logging::LogLevel::Error, $format $(, $args)*)
     };
 }
 
 /// log a warning with Sōzu’s custom log stack
 #[macro_export]
 macro_rules! warn {
     ($format:expr $(, $args:expr)* $(,)?) => {
-        log!($crate::logging::LogLevel::Warn, $format $(, $args)*)
+        $crate::_log!($crate::logging::LogLevel::Warn, $format $(, $args)*)
     };
 }
 
 /// log an info with Sōzu’s custom log stack
 #[macro_export]
 macro_rules! info {
     ($format:expr $(, $args:expr)* $(,)?) => {
-        log!($crate::logging::LogLevel::Info, $format $(, $args)*)
+        $crate::_log!($crate::logging::LogLevel::Info, $format $(, $args)*)
     };
 }
 
@@ -913,7 +919,7 @@ macro_rules! info {
 macro_rules! debug {
     ($format:expr $(, $args:expr)* $(,)?) => {{
         #[cfg(any(debug_assertions, feature = "logs-debug", feature = "logs-trace"))]
-        log!($crate::logging::LogLevel::Debug, concat!("{}\t", $format), module_path!() $(, $args)*);
+        $crate::_log!($crate::logging::LogLevel::Debug, concat!("{}\t", $format), module_path!() $(, $args)*);
         #[cfg(not(any(debug_assertions, feature = "logs-trace")))]
         {$( let _ = $args; )*}
     }};
@@ -924,7 +930,7 @@ macro_rules! debug {
 macro_rules! trace {
     ($format:expr $(, $args:expr)* $(,)?) => {{
         #[cfg(any(debug_assertions, feature = "logs-trace"))]
-        log!($crate::logging::LogLevel::Trace, concat!("{}\t", $format), module_path!() $(, $args)*);
+        $crate::_log!($crate::logging::LogLevel::Trace, concat!("{}\t", $format), module_path!() $(, $args)*);
         #[cfg(not(any(debug_assertions, feature = "logs-trace")))]
         {$( let _ = $args; )*}
     }};
@@ -934,7 +940,7 @@ macro_rules! trace {
 #[macro_export]
 macro_rules! fixme {
     ($(, $args:expr)* $(,)?) => {
-        log!($crate::logging::LogLevel::Info, "FIXME: {}:{} in {}: {}", file!(), line!(), module_path!() $(, $args)*)
+        $crate::_log!($crate::logging::LogLevel::Info, "FIXME: {}:{} in {}: {}", file!(), line!(), module_path!() $(, $args)*)
     };
 }
 
@@ -965,7 +971,7 @@ impl log::Log for CompatLogger {
             }
             let (pid, tag, inner) = logger.split();
             let (now, precise_time) = now();
-            crate::prompt_log! {
+            crate::_prompt_log! {
                 logger: |args| inner.log(args),
                 is_access: false,
                 condition: inner.colored,

diff --git a/e2e/src/tests/tests.rs b/e2e/src/tests/tests.rs
@@ -6,7 +6,7 @@ use std::{
 
 use sozu_command_lib::{
     config::{FileConfig, ListenerBuilder},
-    info, log,
+    info,
     logging::setup_default_logging,
     proto::command::{
         request::RequestType, ActivateListener, AddCertificate, CertificateAndKey, ListenerType,

diff --git a/lib/examples/http.rs b/lib/examples/http.rs
@@ -1,16 +1,12 @@
-extern crate time;
-
 #[macro_use]
 extern crate sozu_command_lib;
 
 use std::{collections::BTreeMap, thread};
 
 use anyhow::Context;
-
 use sozu_command_lib::{
     channel::Channel,
     config::ListenerBuilder,
-    info,
     logging::setup_default_logging,
     proto::command::{
         request::RequestType, AddBackend, Cluster, LoadBalancingAlgorithms, LoadBalancingParams,

diff --git a/lib/examples/https.rs b/lib/examples/https.rs
@@ -1,14 +1,12 @@
-#![allow(unused_variables, unused_must_use)]
+#![allow(unused_must_use)]
 #[macro_use]
 extern crate sozu_lib;
 #[macro_use]
 extern crate sozu_command_lib;
-extern crate time;
 
 use std::thread;
 
 use anyhow::Context;
-
 use sozu_command_lib::{
     channel::Channel,
     config::ListenerBuilder,
@@ -194,6 +192,7 @@ fn main() -> anyhow::Result<()> {
     info!("MAIN\tTLS -> {:?}", command2.read_message());
 
     let _ = jg.join();
+    let _ = jg2.join();
     info!("MAIN\tgood bye");
     Ok(())
 }
diff --git a/lib/examples/tcp.rs b/lib/examples/tcp.rs
@@ -1,8 +1,7 @@
-#![allow(unused_variables, unused_must_use)]
+#![allow(unused_must_use)]
 extern crate sozu_lib;
 #[macro_use]
 extern crate sozu_command_lib;
-extern crate time;
 
 use std::thread;
 
@@ -25,7 +24,6 @@ fn main() -> anyhow::Result<()> {
         Channel::generate(1000, 10000).with_context(|| "should create a channel")?;
 
     let jg = thread::spawn(move || {
-        let max_listeners = 500;
         let max_buffers = 500;
         let buffer_size = 16384;
         let listener = TcpListenerConfig {

diff --git a/lib/src/lib.rs b/lib/src/lib.rs
@@ -209,19 +209,15 @@
 //! Here is the complete example for reference, it matches the `examples/http.rs` example:
 //!
 //! ```
-//! extern crate time;
-//!
 //! #[macro_use]
 //! extern crate sozu_command_lib;
 //!
 //! use std::{collections::BTreeMap, env, io::stdout, thread};
 //!
 //! use anyhow::Context;
-//!
 //! use sozu_command_lib::{
 //!     channel::Channel,
 //!     config::ListenerBuilder,
-//!     info,
 //!     logging::setup_default_logging,
 //!     proto::command::{
 //!         request::RequestType, AddBackend, Cluster, LoadBalancingAlgorithms, LoadBalancingParams,

diff --git a/lib/src/protocol/kawa_h1/mod.rs b/lib/src/protocol/kawa_h1/mod.rs
@@ -823,7 +823,7 @@ impl<Front: SocketHandler, L: ListenerHandler + L7ListenerHandler> Http<Front, L
         }
     }
 
-    pub fn log_request(&mut self, metrics: &SessionMetrics, message: Option<&str>) {
+    pub fn log_request(&self, metrics: &SessionMetrics, error: bool, message: Option<&str>) {
         let listener = self.listener.borrow();
         let tags = self.context.authority.as_ref().and_then(|host| {
             let hostname = match host.split_once(':') {
@@ -836,7 +836,8 @@ impl<Front: SocketHandler, L: ListenerHandler + L7ListenerHandler> Http<Front, L
         let context = self.log_context();
         metrics.register_end_of_session(&context);
 
-        info_access! {
+        log_access! {
+            error,
             message: message,
             context,
             session_address: self.get_session_address(),
@@ -854,21 +855,21 @@ impl<Front: SocketHandler, L: ListenerHandler + L7ListenerHandler> Http<Front, L
         };
     }
 
-    pub fn log_request_success(&mut self, metrics: &SessionMetrics) {
-        self.log_request(metrics, None);
+    pub fn log_request_success(&self, metrics: &SessionMetrics) {
+        self.log_request(metrics, false, None);
     }
-    pub fn log_default_answer_success(&mut self, metrics: &SessionMetrics) {
-        self.log_request(metrics, None);
+    pub fn log_default_answer_success(&self, metrics: &SessionMetrics) {
+        self.log_request(metrics, false, None);
     }
-    pub fn log_request_error(&mut self, metrics: &mut SessionMetrics, message: &str) {
+    pub fn log_request_error(&self, metrics: &mut SessionMetrics, message: &str) {
         incr!("http.errors");
         error!(
             "{} Could not process request properly got: {}",
             self.log_context(),
             message
         );
         self.print_state(self.protocol_string());
-        self.log_request(metrics, Some(message));
+        self.log_request(metrics, true, Some(message));
     }
 
     pub fn set_answer(&mut self, answer: DefaultAnswerStatus, buf: Option<Rc<Vec<u8>>>) {

diff --git a/lib/src/protocol/pipe.rs b/lib/src/protocol/pipe.rs
@@ -212,12 +212,13 @@ impl<Front: SocketHandler, L: ListenerHandler> Pipe<Front, L> {
         }
     }
 
-    pub fn log_request(&self, metrics: &SessionMetrics, message: Option<&str>) {
+    pub fn log_request(&self, metrics: &SessionMetrics, error: bool, message: Option<&str>) {
         let listener = self.listener.borrow();
         let context = self.log_context();
         let endpoint = self.log_endpoint();
         metrics.register_end_of_session(&context);
-        info_access!(
+        log_access!(
+            error,
             message: message,
             context,
             session_address: self.get_session_address(),
@@ -236,7 +237,7 @@ impl<Front: SocketHandler, L: ListenerHandler> Pipe<Front, L> {
     }
 
     pub fn log_request_success(&self, metrics: &SessionMetrics) {
-        self.log_request(metrics, None);
+        self.log_request(metrics, false, None);
     }
 
     pub fn log_request_error(&self, metrics: &SessionMetrics, message: &str) {
@@ -247,7 +248,7 @@ impl<Front: SocketHandler, L: ListenerHandler> Pipe<Front, L> {
             message
         );
         self.print_state(self.protocol_string());
-        self.log_request(metrics, Some(message));
+        self.log_request(metrics, true, Some(message));
     }
 
     pub fn check_connections(&self) -> bool {