From c6f2b4d24ca4d29cbec7c4e7bc894f694e88c8a2 Mon Sep 17 00:00:00 2001 From: Bugen Zhao Date: Mon, 6 Nov 2023 17:53:35 +0800 Subject: [PATCH] record error sources for json format Signed-off-by: Bugen Zhao --- tracing-serde/src/lib.rs | 38 +++++++ tracing-subscriber/src/fmt/format/json.rs | 121 ++++++++++++++++++++-- 2 files changed, 148 insertions(+), 11 deletions(-) diff --git a/tracing-serde/src/lib.rs b/tracing-serde/src/lib.rs index 640c8d7886..4b3f73d5da 100644 --- a/tracing-serde/src/lib.rs +++ b/tracing-serde/src/lib.rs @@ -412,6 +412,44 @@ where self.state = self.serializer.serialize_entry(field.name(), &value) } } + + #[cfg(feature = "std")] + fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) { + if self.state.is_ok() { + self.state = self + .serializer + .serialize_entry(field.name(), &format_args!("{}", value)); + + if self.state.is_ok() { + if let Some(source) = value.source() { + #[derive(Clone, Copy)] + struct ErrorSourceSerializeSeq<'a> { + current: &'a (dyn std::error::Error + 'static), + } + + impl serde::Serialize for ErrorSourceSerializeSeq<'_> { + fn serialize(&self, serializer: S) -> Result + where + S: serde::Serializer, + { + let mut seq = serializer.serialize_seq(None)?; + let mut curr = Some(self.current); + while let Some(curr_err) = curr { + seq.serialize_element(&format_args!("{}", curr_err))?; + curr = curr_err.source(); + } + seq.end() + } + } + + self.state = self.serializer.serialize_entry( + &format_args!("{}.sources", field.name()), + &ErrorSourceSerializeSeq { current: source }, + ); + } + } + } + } } /// Implements `tracing_core::field::Visit` for some `serde::ser::SerializeStruct`. diff --git a/tracing-subscriber/src/fmt/format/json.rs b/tracing-subscriber/src/fmt/format/json.rs index f4e61fb123..ccff09a83b 100644 --- a/tracing-subscriber/src/fmt/format/json.rs +++ b/tracing-subscriber/src/fmt/format/json.rs @@ -7,6 +7,7 @@ use crate::{ }, registry::LookupSpan, }; +use alloc::borrow::Cow; use serde::ser::{SerializeMap, Serializer as _}; use serde_json::Serializer; use std::{ @@ -388,7 +389,7 @@ impl<'a> FormatFields<'a> for JsonFields { // then, we could store fields as JSON values, and add to them // without having to parse and re-serialize. let mut new = String::new(); - let map: BTreeMap<&'_ str, serde_json::Value> = + let map: BTreeMap, serde_json::Value> = serde_json::from_str(current).map_err(|_| fmt::Error)?; let mut v = JsonVisitor::new(&mut new); v.values = map; @@ -405,7 +406,7 @@ impl<'a> FormatFields<'a> for JsonFields { /// [visitor]: crate::field::Visit /// [`MakeVisitor`]: crate::field::MakeVisitor pub struct JsonVisitor<'a> { - values: BTreeMap<&'a str, serde_json::Value>, + values: BTreeMap, serde_json::Value>, writer: &'a mut dyn Write, } @@ -443,7 +444,7 @@ impl<'a> crate::field::VisitOutput for JsonVisitor<'a> { let mut ser_map = serializer.serialize_map(None)?; for (k, v) in self.values { - ser_map.serialize_entry(k, &v)?; + ser_map.serialize_entry(&*k, &v)?; } ser_map.end() @@ -461,31 +462,52 @@ impl<'a> field::Visit for JsonVisitor<'a> { /// Visit a double precision floating point value. fn record_f64(&mut self, field: &Field, value: f64) { self.values - .insert(field.name(), serde_json::Value::from(value)); + .insert(field.name().into(), serde_json::Value::from(value)); } /// Visit a signed 64-bit integer value. fn record_i64(&mut self, field: &Field, value: i64) { self.values - .insert(field.name(), serde_json::Value::from(value)); + .insert(field.name().into(), serde_json::Value::from(value)); } /// Visit an unsigned 64-bit integer value. fn record_u64(&mut self, field: &Field, value: u64) { self.values - .insert(field.name(), serde_json::Value::from(value)); + .insert(field.name().into(), serde_json::Value::from(value)); } /// Visit a boolean value. fn record_bool(&mut self, field: &Field, value: bool) { self.values - .insert(field.name(), serde_json::Value::from(value)); + .insert(field.name().into(), serde_json::Value::from(value)); } /// Visit a string value. fn record_str(&mut self, field: &Field, value: &str) { self.values - .insert(field.name(), serde_json::Value::from(value)); + .insert(field.name().into(), serde_json::Value::from(value)); + } + + fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) { + self.values.insert( + field.name().into(), + serde_json::Value::from(value.to_string()), + ); + + if let Some(source) = value.source() { + let mut sources = Vec::new(); + let mut curr = Some(source); + while let Some(curr_err) = curr { + sources.push(serde_json::Value::from(curr_err.to_string())); + curr = curr_err.source(); + } + + self.values.insert( + format!("{}.sources", field.name()).into(), + serde_json::Value::Array(sources), + ); + } } fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { @@ -494,12 +516,14 @@ impl<'a> field::Visit for JsonVisitor<'a> { #[cfg(feature = "tracing-log")] name if name.starts_with("log.") => (), name if name.starts_with("r#") => { - self.values - .insert(&name[2..], serde_json::Value::from(format!("{:?}", value))); + self.values.insert( + (&name[2..]).into(), + serde_json::Value::from(format!("{:?}", value)), + ); } name => { self.values - .insert(name, serde_json::Value::from(format!("{:?}", value))); + .insert(name.into(), serde_json::Value::from(format!("{:?}", value))); } }; } @@ -778,6 +802,81 @@ mod test { }); } + #[test] + fn json_field_record_error() { + let buffer = MockMakeWriter::default(); + let subscriber = crate::fmt() + .json() + .with_writer(buffer.clone()) + .with_span_events(FmtSpan::NEW) + .finish(); + + #[derive(Debug)] + struct Error { + message: &'static str, + source: Option>, + } + + impl std::fmt::Display for Error { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}", self.message) + } + } + + impl std::error::Error for Error { + fn source(&self) -> Option<&(dyn std::error::Error + 'static)> { + self.source.as_ref().map(|e| e.as_ref() as _) + } + } + + let error = Error { + message: "outer", + source: Some( + Error { + message: "middle", + source: Some( + Error { + message: "inner", + source: None, + } + .into(), + ), + } + .into(), + ), + }; + + with_default(subscriber, || { + // Event: `tracing_serde::SerdeMapVisitor` + { + tracing::info!(error = &error as &dyn std::error::Error, "event"); + let event = parse_as_json(&buffer); + + assert_eq!(event["fields"]["message"], "event"); + assert_eq!(event["fields"]["error"], "outer"); + assert_eq!( + event["fields"]["error.sources"].as_array().unwrap().len(), + 2 + ); + assert_eq!(event["fields"]["error.sources"][0], "middle"); + assert_eq!(event["fields"]["error.sources"][1], "inner"); + } + + // Span: `tracing_subscriber::fmt::json::JsonVisitor` + { + let _span = + tracing::info_span!("parent_span", error = &error as &dyn std::error::Error); + let event = parse_as_json(&buffer); + + assert_eq!(event["span"]["name"], "parent_span"); + assert_eq!(event["span"]["error"], "outer"); + assert_eq!(event["span"]["error.sources"].as_array().unwrap().len(), 2); + assert_eq!(event["span"]["error.sources"][0], "middle"); + assert_eq!(event["span"]["error.sources"][1], "inner"); + } + }) + } + fn parse_as_json(buffer: &MockMakeWriter) -> serde_json::Value { let buf = String::from_utf8(buffer.buf().to_vec()).unwrap(); let json = buf