add tracing event formatter with trace_id and span_id

Cargo.lock

@@ -6640,6 +6640,7 @@ dependencies = [
  "cargo_metadata 0.19.2",
  "celes",
  "chacha",
+ "chrono",
  "clap",
  "colored",
  "criterion",
@@ -6707,6 +6708,7 @@ dependencies = [
  "tracing-core",
  "tracing-indicatif",
  "tracing-opentelemetry",
+ "tracing-serde",
  "tracing-subscriber",
  "url",
  "utoipa",

Cargo.toml

@@ -345,6 +345,7 @@ tracing = "0.1.41"
 tracing-core = "0.1.33"
 tracing-log = "0.2"
 tracing-opentelemetry = "0.31.0"
+tracing-serde = "0.2.0"
 tracing-subscriber = "0.3.19"
 tracing-tree = "0.2.2"
 tracing-indicatif = "0.3.9"

nym-node/Cargo.toml

@@ -119,11 +119,13 @@ opentelemetry = { workspace = true }
 opentelemetry_sdk = { workspace = true }
 tracing-core = { workspace = true }
 tracing-opentelemetry = { workspace = true }
+tracing-serde = { workspace = true }
 opentelemetry-otlp = { version = "0.30.0" }
 opentelemetry-semantic-conventions = { workspace = true, features = [
     "semconv_experimental",
 ] }
 opentelemetry-stdout = { workspace = true, features = ["trace", "metrics"] }
+chrono = { workspace = true }
 
 [[bench]]
 name = "benchmarks"

nym-node/src/logging.rs

@@ -9,6 +9,7 @@ use tracing_subscriber::util::SubscriberInitExt;
 use tracing_subscriber::{fmt, Layer};
 
 // Signoz
+use crate::trace_id_format::TraceIdFormat;
 use opentelemetry::trace::TracerProvider;
 use opentelemetry::{global, KeyValue};
 use opentelemetry_otlp::tonic_types::metadata::MetadataMap;
@@ -55,7 +56,8 @@ pub(crate) fn build_tracing_logger() -> anyhow::Result<impl SubscriberExt> {
         .with_writer(std::io::stderr)
         .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
         .with_span_list(false)
-        .with_current_span(true);
+        .with_current_span(true)
+        .event_format(TraceIdFormat);
 
     let registry = tracing_subscriber::registry()
         .with(fmt_layer)

nym-node/src/main.rs

@@ -16,6 +16,7 @@ pub(crate) mod error;
 mod logging;
 pub(crate) mod node;
 pub(crate) mod throughput_tester;
+mod trace_id_format;
 pub(crate) mod wireguard;
 
 fn main() -> anyhow::Result<()> {

nym-node/src/trace_id_format.rs

@@ -0,0 +1,88 @@
+use chrono::Utc;
+use opentelemetry::trace::TraceContextExt;
+use opentelemetry::{SpanId, TraceId};
+use serde::ser::{SerializeMap, Serializer as _};
+use std::io;
+use tracing::{Event, Subscriber};
+use tracing_opentelemetry::OpenTelemetrySpanExt;
+use tracing_serde::fields::AsMap;
+use tracing_serde::AsSerde;
+use tracing_subscriber::fmt::format::Writer;
+use tracing_subscriber::fmt::{FmtContext, FormatEvent, FormatFields};
+use tracing_subscriber::registry::LookupSpan;
+
+pub struct WriteAdaptor<'a> {
+    fmt_write: &'a mut dyn std::fmt::Write,
+}
+
+impl<'a> WriteAdaptor<'a> {
+    pub fn new(fmt_write: &'a mut dyn std::fmt::Write) -> Self {
+        Self { fmt_write }
+    }
+}
+
+impl<'a> io::Write for WriteAdaptor<'a> {
+    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+        let s =
+            std::str::from_utf8(buf).map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?;
+
+        self.fmt_write
+            .write_str(s)
+            .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
+
+        Ok(s.as_bytes().len())
+    }
+
+    fn flush(&mut self) -> io::Result<()> {
+        Ok(())
+    }
+}
+
+pub struct TraceIdFormat;
+
+impl<S, N> FormatEvent<S, N> for TraceIdFormat
+where
+    S: Subscriber + for<'lookup> LookupSpan<'lookup>,
+    N: for<'writer> FormatFields<'writer> + 'static,
+{
+    fn format_event(
+        &self,
+        _ctx: &FmtContext<'_, S, N>,
+        mut writer: Writer<'_>,
+        event: &Event<'_>,
+    ) -> std::fmt::Result
+    where
+        S: Subscriber + for<'a> LookupSpan<'a>,
+    {
+        let meta = event.metadata();
+
+        let mut visit = || {
+            let mut serializer = serde_json::Serializer::new(WriteAdaptor::new(&mut writer));
+            let mut serializer = serializer.serialize_map(None)?;
+            serializer.serialize_entry("timestamp", &Utc::now().to_rfc3339())?;
+            serializer.serialize_entry("level", &meta.level().as_serde())?;
+            serializer.serialize_entry("fields", &event.field_map())?;
+            serializer.serialize_entry("target", meta.target())?;
+
+            let current_span = tracing::Span::current();
+            let context = current_span.context();
+            let span_ref = context.span();
+            let span_context = span_ref.span_context();
+
+            let trace_id = span_context.trace_id();
+            if trace_id != TraceId::INVALID {
+                serializer.serialize_entry("trace_id", &trace_id.to_string())?;
+
+                let span_id = span_context.span_id();
+                if span_id != SpanId::INVALID {
+                    serializer.serialize_entry("span_id", &span_id.to_string())?;
+                }
+            }
+
+            serializer.end()
+        };
+
+        visit().map_err(|_| std::fmt::Error)?;
+        writeln!(writer)
+    }
+}