diff --git a/crates/router/src/routes/health.rs b/crates/router/src/routes/health.rs index 721dbd6a78..3e2f42bcc2 100644 --- a/crates/router/src/routes/health.rs +++ b/crates/router/src/routes/health.rs @@ -16,6 +16,7 @@ use crate::{ pub async fn health() -> impl actix_web::Responder { metrics::HEALTH_METRIC.add(&metrics::CONTEXT, 1, &[]); logger::info!("Health was called"); + actix_web::HttpResponse::Ok().body("health is good") } diff --git a/crates/router_env/src/logger/formatter.rs b/crates/router_env/src/logger/formatter.rs index 472b917e74..30a80aa15d 100644 --- a/crates/router_env/src/logger/formatter.rs +++ b/crates/router_env/src/logger/formatter.rs @@ -58,7 +58,6 @@ const SESSION_ID: &str = "session_id"; pub static IMPLICIT_KEYS: Lazy> = Lazy::new(|| { let mut set = rustc_hash::FxHashSet::default(); - set.insert(MESSAGE); set.insert(HOSTNAME); set.insert(PID); set.insert(ENV); @@ -81,6 +80,7 @@ pub static IMPLICIT_KEYS: Lazy> = Lazy::new(|| { pub static EXTRA_IMPLICIT_KEYS: Lazy> = Lazy::new(|| { let mut set = rustc_hash::FxHashSet::default(); + set.insert(MESSAGE); set.insert(FLOW); set.insert(MERCHANT_AUTH); set.insert(MERCHANT_ID); @@ -163,7 +163,7 @@ where pub fn new_with_implicit_entries( service: &str, dst_writer: W, - default_fields: HashMap, + mut default_fields: HashMap, formatter: F, ) -> Self { let pid = std::process::id(); @@ -174,6 +174,18 @@ where #[cfg(feature = "vergen")] let build = crate::build!().to_string(); let env = crate::env::which().to_string(); + default_fields.retain(|key, value| { + if !IMPLICIT_KEYS.contains(key.as_str()) { + true + } else { + tracing::warn!( + ?key, + ?value, + "Attempting to log a reserved entry. It won't be added to the logs" + ); + false + } + }); Self { dst_writer, @@ -196,9 +208,8 @@ where map_serializer: &mut impl SerializeMap, metadata: &Metadata<'_>, span: Option<&SpanRef<'_, S>>, - storage: Option<&Storage<'_>>, + storage: &Storage<'_>, name: &str, - message: &str, ) -> Result<(), std::io::Error> where S: Subscriber + for<'a> LookupSpan<'a>, @@ -206,7 +217,6 @@ where let is_extra = |s: &str| !IMPLICIT_KEYS.contains(s); let is_extra_implicit = |s: &str| is_extra(s) && EXTRA_IMPLICIT_KEYS.contains(s); - map_serializer.serialize_entry(MESSAGE, &message)?; map_serializer.serialize_entry(HOSTNAME, &self.hostname)?; map_serializer.serialize_entry(PID, &self.pid)?; map_serializer.serialize_entry(ENV, &self.env)?; @@ -228,30 +238,30 @@ where // Write down implicit default entries. for (key, value) in self.default_fields.iter() { - if !IMPLICIT_KEYS.contains(key.as_str()) { - map_serializer.serialize_entry(key, value)?; - } else { - tracing::warn!("{} is a reserved field. Skipping it.", key); - } + map_serializer.serialize_entry(key, value)?; } #[cfg(feature = "log_custom_entries_to_extra")] let mut extra = serde_json::Map::default(); let mut explicit_entries_set: HashSet<&str> = HashSet::default(); // Write down explicit event's entries. - if let Some(storage) = storage { - for (key, value) in storage.values.iter() { - if is_extra_implicit(key) { - #[cfg(feature = "log_extra_implicit_fields")] - map_serializer.serialize_entry(key, value)?; - explicit_entries_set.insert(key); - } else if is_extra(key) { - #[cfg(feature = "log_custom_entries_to_extra")] - extra.insert(key.to_string(), value.clone()); - #[cfg(not(feature = "log_custom_entries_to_extra"))] - map_serializer.serialize_entry(key, value)?; - explicit_entries_set.insert(key); - } + for (key, value) in storage.values.iter() { + if is_extra_implicit(key) { + #[cfg(feature = "log_extra_implicit_fields")] + map_serializer.serialize_entry(key, value)?; + explicit_entries_set.insert(key); + } else if is_extra(key) { + #[cfg(feature = "log_custom_entries_to_extra")] + extra.insert(key.to_string(), value.clone()); + #[cfg(not(feature = "log_custom_entries_to_extra"))] + map_serializer.serialize_entry(key, value)?; + explicit_entries_set.insert(key); + } else { + tracing::warn!( + ?key, + ?value, + "Attempting to log a reserved entry. It won't be added to the logs" + ); } } @@ -269,7 +279,11 @@ where #[cfg(not(feature = "log_custom_entries_to_extra"))] map_serializer.serialize_entry(key, value)?; } else { - tracing::debug!("{} is a reserved entry. Skipping it.", key); + tracing::warn!( + ?key, + ?value, + "Attempting to log a reserved entry. It won't be added to the logs" + ); } } } @@ -305,14 +319,15 @@ where 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); + let mut storage = Storage::default(); + storage.record_value("message", message.into()); self.common_serialize( &mut map_serializer, span.metadata(), Some(span), - None, + &storage, span.name(), - &message, )?; map_serializer.end()?; @@ -337,16 +352,9 @@ where event.record(&mut storage); let name = span.map_or("?", SpanRef::name); - let message = Self::event_message(span, event, &storage); + Self::event_message(span, event, &mut storage); - self.common_serialize( - &mut map_serializer, - event.metadata(), - *span, - Some(&storage), - name, - &message, - )?; + self.common_serialize(&mut map_serializer, event.metadata(), *span, &storage, name)?; map_serializer.end()?; Ok(buffer) @@ -374,32 +382,20 @@ where fn event_message( span: &Option<&SpanRef<'_, S>>, event: &Event<'_>, - storage: &Storage<'_>, - ) -> String - where + storage: &mut Storage<'_>, + ) where S: Subscriber + for<'a> LookupSpan<'a>, { // Get value of kept "message" or "target" if does not exist. - let mut message = storage + let message = storage .values - .get("message") - .and_then(|v| match v { - Value::String(s) => Some(s.as_str()), - _ => None, - }) - .unwrap_or_else(|| event.metadata().target()) - .to_owned(); + .entry("message") + .or_insert_with(|| event.metadata().target().into()); // Prepend the span name to the message if span exists. - if let Some(span) = span { - message = format!( - "{} {}", - Self::span_message(span, RecordType::Event), - message, - ); + if let (Some(span), Value::String(a)) = (span, message) { + *a = format!("{} {}", Self::span_message(span, RecordType::Event), a,); } - - message } } diff --git a/crates/router_env/src/logger/storage.rs b/crates/router_env/src/logger/storage.rs index a134bbed73..ce220680bb 100644 --- a/crates/router_env/src/logger/storage.rs +++ b/crates/router_env/src/logger/storage.rs @@ -28,6 +28,14 @@ impl<'a> Storage<'a> { pub fn new() -> Self { Self::default() } + + pub fn record_value(&mut self, key: &'a str, value: serde_json::Value) { + if super::formatter::IMPLICIT_KEYS.contains(key) { + tracing::warn!(value =? value, "{} is a reserved entry. Skipping it.", key); + } else { + self.values.insert(key, value); + } + } } /// Default constructor. @@ -43,32 +51,27 @@ impl Default for Storage<'_> { impl Visit for Storage<'_> { /// A i64. fn record_i64(&mut self, field: &Field, value: i64) { - self.values - .insert(field.name(), serde_json::Value::from(value)); + self.record_value(field.name(), serde_json::Value::from(value)); } /// A u64. fn record_u64(&mut self, field: &Field, value: u64) { - self.values - .insert(field.name(), serde_json::Value::from(value)); + self.record_value(field.name(), serde_json::Value::from(value)); } /// A 64-bit floating point. fn record_f64(&mut self, field: &Field, value: f64) { - self.values - .insert(field.name(), serde_json::Value::from(value)); + self.record_value(field.name(), serde_json::Value::from(value)); } /// A boolean. fn record_bool(&mut self, field: &Field, value: bool) { - self.values - .insert(field.name(), serde_json::Value::from(value)); + self.record_value(field.name(), serde_json::Value::from(value)); } /// A string. fn record_str(&mut self, field: &Field, value: &str) { - self.values - .insert(field.name(), serde_json::Value::from(value)); + self.record_value(field.name(), serde_json::Value::from(value)); } /// Otherwise. @@ -77,7 +80,7 @@ impl Visit for Storage<'_> { // Skip fields which are already handled name if name.starts_with("log.") => (), name if name.starts_with("r#") => { - self.values.insert( + self.record_value( #[allow(clippy::expect_used)] name.get(2..) .expect("field name must have a minimum of two characters"), @@ -85,8 +88,7 @@ impl Visit for Storage<'_> { ); } name => { - self.values - .insert(name, serde_json::Value::from(format!("{value:?}"))); + self.record_value(name, serde_json::Value::from(format!("{value:?}"))); } }; } @@ -165,7 +167,7 @@ impl tracing_subscriber::registry::LookupSpan<'a>> Layer span.parent().and_then(|p| { p.extensions_mut() .get_mut::>() - .map(|s| s.values.insert(k, v.to_owned())) + .map(|s| s.record_value(k, v.to_owned())) }); } }) @@ -178,7 +180,7 @@ impl tracing_subscriber::registry::LookupSpan<'a>> Layer .expect("No visitor in extensions"); if let Ok(elapsed) = serde_json::to_value(elapsed_milliseconds) { - visitor.values.insert("elapsed_milliseconds", elapsed); + visitor.record_value("elapsed_milliseconds", elapsed); } } }