Skip to content

subscriber: record error sources in fmt layer with JSON format #2797

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 1 commit into from
Closed

subscriber: record error sources in fmt layer with JSON format #2797

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
38 changes: 38 additions & 0 deletions tracing-serde/src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
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`.
Expand Down
121 changes: 110 additions & 11 deletions tracing-subscriber/src/fmt/format/json.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ use crate::{
},
registry::LookupSpan,
};
use alloc::borrow::Cow;
use serde::ser::{SerializeMap, Serializer as _};
use serde_json::Serializer;
use std::{
Expand Down Expand Up @@ -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<Cow<'_, str>, serde_json::Value> =
serde_json::from_str(current).map_err(|_| fmt::Error)?;
let mut v = JsonVisitor::new(&mut new);
v.values = map;
Expand All @@ -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<Cow<'a, str>, serde_json::Value>,
writer: &'a mut dyn Write,
}

Expand Down Expand Up @@ -443,7 +444,7 @@ impl<'a> crate::field::VisitOutput<fmt::Result> 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()
Expand All @@ -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) {
Expand All @@ -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)));
}
};
}
Expand Down Expand Up @@ -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<Box<Error>>,
}

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
Expand Down