fix(logging): fix missing fields in consolidated log line (#3684)

crates/router/src/middleware.rs

@@ -143,7 +143,7 @@ where
         Box::pin(
             async move {
                 let response = response_fut.await;
-                logger::info!(golden_log_line = true);
+                router_env::tracing::Span::current().record("golden_log_line", true);
                 response
             }
             .instrument(
@@ -153,7 +153,8 @@ where
                     merchant_id = Empty,
                     connector_name = Empty,
                     payment_method = Empty,
-                    flow = "UNKNOWN"
+                    flow = "UNKNOWN",
+                    golden_log_line = Empty
                 )
                 .or_current(),
             ),

crates/router_env/src/logger/config.rs

@@ -107,13 +107,15 @@ pub struct LogTelemetry {
 
 /// Telemetry / tracing.
 #[derive(Default, Debug, Deserialize, Clone, PartialEq, Eq)]
-#[serde(rename_all = "lowercase")]
+#[serde(rename_all = "snake_case")]
 pub enum LogFormat {
     /// Default pretty log format
     Default,
     /// JSON based structured logging
     #[default]
     Json,
+    /// JSON based structured logging with pretty print
+    PrettyJson,
 }
 
 impl Config {

crates/router_env/src/logger/formatter.rs

@@ -10,7 +10,7 @@ use std::{
 
 use once_cell::sync::Lazy;
 use serde::ser::{SerializeMap, Serializer};
-use serde_json::Value;
+use serde_json::{ser::Formatter, Value};
 // use time::format_description::well_known::Rfc3339;
 use time::format_description::well_known::Iso8601;
 use tracing::{Event, Metadata, Subscriber};
@@ -121,9 +121,10 @@ impl fmt::Display for RecordType {
 /// `FormattingLayer` relies on the `tracing_bunyan_formatter::JsonStorageLayer` which is storage of entries.
 ///
 #[derive(Debug)]
-pub struct FormattingLayer<W>
+pub struct FormattingLayer<W, F>
 where
     W: for<'a> MakeWriter<'a> + 'static,
+    F: Formatter + Clone,
 {
     dst_writer: W,
     pid: u32,
@@ -135,11 +136,13 @@ where
     #[cfg(feature = "vergen")]
     build: String,
     default_fields: HashMap<String, Value>,
+    formatter: F,
 }
 
-impl<W> FormattingLayer<W>
+impl<W, F> FormattingLayer<W, F>
 where
     W: for<'a> MakeWriter<'a> + 'static,
+    F: Formatter + Clone,
 {
     ///
     /// Constructor of `FormattingLayer`.
@@ -149,11 +152,11 @@ where
     ///
     /// ## Example
     /// ```rust
-    /// let formatting_layer = router_env::FormattingLayer::new(router_env::service_name!(),std::io::stdout);
+    /// let formatting_layer = router_env::FormattingLayer::new(router_env::service_name!(),std::io::stdout, CompactFormatter);
     /// ```
     ///
-    pub fn new(service: &str, dst_writer: W) -> Self {
+    pub fn new(service: &str, dst_writer: W, formatter: F) -> Self {
-        Self::new_with_implicit_entries(service, dst_writer, HashMap::new())
+        Self::new_with_implicit_entries(service, dst_writer, HashMap::new(), formatter)
     }
 
     /// Construct of `FormattingLayer with implicit default entries.
@@ -161,6 +164,7 @@ where
         service: &str,
         dst_writer: W,
         default_fields: HashMap<String, Value>,
+        formatter: F,
     ) -> Self {
         let pid = std::process::id();
         let hostname = gethostname::gethostname().to_string_lossy().into_owned();
@@ -182,6 +186,7 @@ where
             #[cfg(feature = "vergen")]
             build,
             default_fields,
+            formatter,
         }
     }
 
@@ -287,7 +292,6 @@ where
     }
 
     /// Serialize entries of span.
-    #[cfg(feature = "log_active_span_json")]
     fn span_serialize<S>(
         &self,
         span: &SpanRef<'_, S>,
@@ -297,7 +301,8 @@ where
         S: Subscriber + for<'a> LookupSpan<'a>,
     {
         let mut buffer = Vec::new();
-        let mut serializer = serde_json::Serializer::new(&mut buffer);
+        let mut serializer =
+            serde_json::Serializer::with_formatter(&mut buffer, self.formatter.clone());
         let mut map_serializer = serializer.serialize_map(None)?;
         let message = Self::span_message(span, ty);
 
@@ -324,7 +329,8 @@ where
         S: Subscriber + for<'a> LookupSpan<'a>,
     {
         let mut buffer = Vec::new();
-        let mut serializer = serde_json::Serializer::new(&mut buffer);
+        let mut serializer =
+            serde_json::Serializer::with_formatter(&mut buffer, self.formatter.clone());
         let mut map_serializer = serializer.serialize_map(None)?;
 
         let mut storage = Storage::default();
@@ -398,10 +404,11 @@ where
 }
 
 #[allow(clippy::expect_used)]
-impl<S, W> Layer<S> for FormattingLayer<W>
+impl<S, W, F> Layer<S> for FormattingLayer<W, F>
 where
     S: Subscriber + for<'a> LookupSpan<'a>,
     W: for<'a> MakeWriter<'a> + 'static,
+    F: Formatter + Clone + 'static,
 {
     fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
         // Event could have no span.
@@ -421,6 +428,16 @@ where
         }
     }
 
+    #[cfg(not(feature = "log_active_span_json"))]
+    fn on_close(&self, id: tracing::Id, ctx: Context<'_, S>) {
+        let span = ctx.span(&id).expect("No span");
+        if span.parent().is_none() {
+            if let Ok(serialized) = self.span_serialize(&span, RecordType::ExitSpan) {
+                let _ = self.flush(serialized);
+            }
+        }
+    }
+
     #[cfg(feature = "log_active_span_json")]
     fn on_close(&self, id: tracing::Id, ctx: Context<'_, S>) {
         let span = ctx.span(&id).expect("No span");

crates/router_env/src/logger/setup.rs

@@ -16,6 +16,7 @@ use opentelemetry::{
     KeyValue,
 };
 use opentelemetry_otlp::{TonicExporterBuilder, WithExportConfig};
+use serde_json::ser::{CompactFormatter, PrettyFormatter};
 use tracing_appender::non_blocking::WorkerGuard;
 use tracing_subscriber::{fmt, prelude::*, util::SubscriberInitExt, EnvFilter, Layer};
 
@@ -69,7 +70,10 @@ pub fn setup(
         );
         println!("Using file logging filter: {file_filter}");
 
-        Some(FormattingLayer::new(service_name, file_writer).with_filter(file_filter))
+        Some(
+            FormattingLayer::new(service_name, file_writer, CompactFormatter)
+                .with_filter(file_filter),
+        )
     } else {
         None
     };
@@ -104,7 +108,15 @@ pub fn setup(
             config::LogFormat::Json => {
                 error_stack::Report::set_color_mode(error_stack::fmt::ColorMode::None);
                 let logging_layer =
-                    FormattingLayer::new(service_name, console_writer).with_filter(console_filter);
+                    FormattingLayer::new(service_name, console_writer, CompactFormatter)
+                        .with_filter(console_filter);
+                subscriber.with(logging_layer).init();
+            }
+            config::LogFormat::PrettyJson => {
+                error_stack::Report::set_color_mode(error_stack::fmt::ColorMode::None);
+                let logging_layer =
+                    FormattingLayer::new(service_name, console_writer, PrettyFormatter::new())
+                        .with_filter(console_filter);
                 subscriber.with(logging_layer).init();
             }
         }