telemetry_rust/
fmt.rs

1//! JSON formatting utilities for structured logging with OpenTelemetry.
2
3use opentelemetry::trace::TraceContextExt;
4use serde::{
5    Deserialize, Deserializer as _, Serialize, Serializer as _,
6    de::{Error, MapAccess, Visitor as DeVisitor},
7    ser::{SerializeMap, SerializeSeq},
8};
9use serde_json::{Deserializer, Serializer, Value};
10use std::{fmt, io, marker::PhantomData, ops::Deref, str};
11use tracing::{Event, Span, Subscriber};
12use tracing_opentelemetry::OpenTelemetrySpanExt;
13use tracing_serde::{AsSerde, SerdeMapVisitor};
14use tracing_subscriber::{
15    fmt::{
16        FmtContext, FormatEvent, FormatFields, FormattedFields,
17        format::Writer,
18        time::{FormatTime, SystemTime},
19    },
20    registry::{LookupSpan, SpanRef},
21};
22
23/// JSON event formatter for structured logging with OpenTelemetry integration.
24///
25/// This formatter serializes tracing events into JSON format with additional OpenTelemetry
26/// metadata including trace IDs, span IDs, and span hierarchy information. It's designed
27/// to work with the tracing-subscriber ecosystem and provides rich context for log analysis.
28///
29/// # Features
30///
31/// - Structured JSON output with consistent field names
32/// - Automatic inclusion of OpenTelemetry trace and span IDs
33/// - Hierarchical span information for request tracing
34/// - ISO 8601 timestamp formatting
35/// - Proper handling of event fields and metadata
36///
37/// # JSON Structure
38///
39/// The generated JSON includes the following fields:
40/// - `timestamp`: ISO 8601 formatted timestamp
41/// - `level`: Log level (ERROR, WARN, INFO, DEBUG, TRACE)
42/// - `target`: The module path where the event was recorded
43/// - `trace_id`: OpenTelemetry trace ID (if available)
44/// - `span_id`: OpenTelemetry span ID (if available)
45/// - `spans`: Array of parent spans with their fields
46/// - Additional fields from the log event, including `message`
47pub struct JsonFormat;
48
49impl<S, N> FormatEvent<S, N> for JsonFormat
50where
51    S: Subscriber + for<'lookup> LookupSpan<'lookup>,
52    N: for<'writer> FormatFields<'writer> + 'static,
53{
54    fn format_event(
55        &self,
56        ctx: &FmtContext<'_, S, N>,
57        mut writer: Writer<'_>,
58        event: &Event<'_>,
59    ) -> fmt::Result {
60        let mut timestamp = String::new();
61        SystemTime.format_time(&mut Writer::new(&mut timestamp))?;
62
63        let meta = event.metadata();
64
65        let mut visit = || {
66            let mut serializer = Serializer::new(IoWriter(&mut writer));
67            let mut serializer = serializer.serialize_map(None)?;
68
69            serializer.serialize_entry("timestamp", &timestamp)?;
70            serializer.serialize_entry("level", &meta.level().as_serde())?;
71
72            // add all event fields to the json object
73            let mut visitor = SerdeMapVisitor::new(serializer);
74            event.record(&mut visitor);
75            serializer = visitor.take_serializer()?;
76
77            serializer.serialize_entry("target", meta.target())?;
78
79            // extract tracing information from the current span context
80            let current_span = Span::current();
81            if let Some(id) = current_span.id() {
82                let otel_ctx = current_span.context();
83                let span_ref = otel_ctx.span();
84                let span_context = span_ref.span_context();
85
86                if let Some(leaf_span) = ctx.span(&id).or_else(|| ctx.lookup_current()) {
87                    let spans = SpanScope(leaf_span, PhantomData::<N>);
88                    serializer.serialize_entry("spans", &spans)?;
89                }
90
91                let trace_id = span_context.trace_id().to_string();
92                serializer.serialize_entry("trace_id", &trace_id)?;
93
94                let span_id = span_context.span_id().to_string();
95                serializer.serialize_entry("span_id", &span_id)?;
96            }
97
98            SerializeMap::end(serializer)
99        };
100
101        visit().map_err(|_| fmt::Error)?;
102        writeln!(writer)
103    }
104}
105
106struct IoWriter<'a>(&'a mut dyn fmt::Write);
107
108impl io::Write for IoWriter<'_> {
109    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
110        let s = str::from_utf8(buf)
111            .map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?;
112
113        self.0.write_str(s).map_err(io::Error::other)?;
114
115        Ok(s.len())
116    }
117
118    fn flush(&mut self) -> io::Result<()> {
119        Ok(())
120    }
121}
122
123struct SpanData<'a, R, N>(SpanRef<'a, R>, PhantomData<N>)
124where
125    R: for<'lookup> LookupSpan<'lookup>,
126    N: for<'writer> FormatFields<'writer> + 'static;
127
128impl<R, N> Serialize for SpanData<'_, R, N>
129where
130    R: for<'lookup> LookupSpan<'lookup>,
131    N: for<'writer> FormatFields<'writer> + 'static,
132{
133    fn serialize<S: serde::Serializer>(&self, serializer: S) -> Result<S::Ok, S::Error> {
134        let mut serializer = serializer.serialize_map(None)?;
135        serializer.serialize_entry("name", self.0.name())?;
136
137        let extensions = self.0.extensions();
138        if let Some(fields) = extensions.get::<FormattedFields<N>>() {
139            let mut deserializer = Deserializer::from_str(fields);
140            let visitor = SerializeMapVisitor(&mut serializer);
141            if let Err(error) = deserializer.deserialize_map(visitor) {
142                serializer.serialize_entry("formatted_fields", fields.deref())?;
143                serializer.serialize_entry("parsing_error", &format!("{error:?}"))?;
144            }
145        }
146
147        serializer.end()
148    }
149}
150
151struct SpanScope<'a, R, N>(SpanRef<'a, R>, PhantomData<N>)
152where
153    R: Subscriber + for<'lookup> LookupSpan<'lookup>,
154    N: for<'writer> FormatFields<'writer> + 'static;
155
156impl<R, N> Serialize for SpanScope<'_, R, N>
157where
158    R: Subscriber + for<'lookup> LookupSpan<'lookup>,
159    N: for<'writer> FormatFields<'writer> + 'static,
160{
161    fn serialize<S: serde::Serializer>(&self, serializer: S) -> Result<S::Ok, S::Error> {
162        let mut serializer = serializer.serialize_seq(None)?;
163        for span in self.0.scope().from_root() {
164            serializer.serialize_element(&SpanData(span, self.1))?;
165        }
166        serializer.end()
167    }
168}
169
170#[derive(Debug, PartialEq, Serialize, Deserialize)]
171#[serde(untagged)]
172enum SpanFieldsValue<'a> {
173    /// String which could be borrowed directly from the input json
174    Borrowed(&'a str),
175    /// Any other value
176    Owned(Value),
177}
178
179/// The [serde::de::Visitor] which moves entries from one map to another.
180struct SerializeMapVisitor<'a, S: SerializeMap>(&'a mut S);
181
182impl<'de, S: SerializeMap> DeVisitor<'de> for SerializeMapVisitor<'_, S> {
183    type Value = ();
184
185    fn expecting(&self, formatter: &mut fmt::Formatter) -> fmt::Result {
186        write!(formatter, "a map of values")
187    }
188
189    fn visit_map<A: MapAccess<'de>>(self, mut map: A) -> Result<Self::Value, A::Error> {
190        while let Some((key, value)) = map.next_entry::<&str, SpanFieldsValue>()? {
191            self.0
192                .serialize_entry(key, &value)
193                .map_err(A::Error::custom)?;
194        }
195        Ok(())
196    }
197}
198
199#[cfg(test)]
200mod tests {
201    use assert2::assert;
202    use rstest::rstest;
203    use serde::Serialize;
204
205    use super::*;
206
207    // Normal strings should be parsed as borrowed &str
208    #[rstest]
209    #[case("Hello worlds!")]
210    #[case("123.456")]
211    #[case("true")]
212    #[case("null")]
213    #[case("42")]
214    fn test_borrowed_field_value(#[case] value: &str) {
215        let json = format!("\"{value}\"");
216        let actual = serde_json::from_str::<SpanFieldsValue>(&json)
217            .map_err(|err| format!("Error parsing {json:?}: {err:?}"))
218            .unwrap();
219        assert!(actual == SpanFieldsValue::Borrowed(value));
220    }
221
222    // Strings containeng escape sequences and non-string values should be parsed as owned values
223    #[rstest]
224    #[case("Qwe\\rty")]
225    #[case("\"\"")]
226    #[case(true)]
227    #[case(false)]
228    #[case(123.456)]
229    #[case(i64::MIN)]
230    #[case(u64::MAX)]
231    #[case(())]
232    fn test_owned_field_value<T: Serialize + Into<Value>>(#[case] value: T) {
233        let json = serde_json::to_string(&value).unwrap();
234        let actual = serde_json::from_str::<SpanFieldsValue>(&json)
235            .map_err(|err| format!("Error parsing {json:?}: {err:?}"))
236            .unwrap();
237        assert!(actual == SpanFieldsValue::Owned(value.into()));
238    }
239}
telemetry_rust/fmt.rs

telemetry_rust/
fmt.rs
