From c744b2f8bebfd7b53a454096aa7044cf12df4802 Mon Sep 17 00:00:00 2001 From: Lily Mara <54288692+lilymara-onesignal@users.noreply.github.com> Date: Fri, 20 May 2022 12:58:12 -0700 Subject: [PATCH] opentelemetry: record error source chain (#2122) Previously error values were recorded using their `Debug` representation. They are now reported with their `Display` implementation. This is more in line with current best practices for error handling. This is a change in how error values are recorded in the opentelemetry adapter. For a given field `x` that contains an error type, record an additional dynamic field `x.chain` that contains an array of all errors in the source chain. This allows users to determine where a high-level error originated. ## Motivation Rust's `Error` type includes a `source` method which allows library authors to compose errors on top of one another in a way that indicates how errors originated down to the OS level. Surfacing this information to the users will allow them to determine why errors are occurring with more detail. ## Solution Walking the `source` chain until there are no errors left and storing this at a new field called `{fieldname}.chain` allows operators to determine the causal chain of complex errors. --- tracing-opentelemetry/src/layer.rs | 99 ++++++++++++++++++++++++++++++ 1 file changed, 99 insertions(+) diff --git a/tracing-opentelemetry/src/layer.rs b/tracing-opentelemetry/src/layer.rs index 0c21caab2f..bdaf1c32fa 100644 --- a/tracing-opentelemetry/src/layer.rs +++ b/tracing-opentelemetry/src/layer.rs @@ -4,6 +4,7 @@ use opentelemetry::{ Context as OtelContext, Key, KeyValue, Value, }; use std::any::TypeId; +use std::borrow::Cow; use std::fmt; use std::marker; use std::time::{Instant, SystemTime}; @@ -253,6 +254,27 @@ impl<'a> field::Visit for SpanAttributeVisitor<'a> { _ => self.record(Key::new(field.name()).string(format!("{:?}", value))), } } + + /// Set attributes on the underlying OpenTelemetry [`Span`] using a [`std::error::Error`]'s + /// [`std::fmt::Display`] implementation. Also adds the `source` chain as an extra field + /// + /// [`Span`]: opentelemetry::trace::Span + fn record_error( + &mut self, + field: &tracing_core::Field, + value: &(dyn std::error::Error + 'static), + ) { + let mut chain = Vec::new(); + let mut next_err = value.source(); + + while let Some(err) = next_err { + chain.push(Cow::Owned(err.to_string())); + next_err = err.source(); + } + + self.record(Key::new(field.name()).string(value.to_string())); + self.record(Key::new(format!("{}.chain", field.name())).array(chain)); + } } impl OpenTelemetryLayer @@ -684,6 +706,7 @@ mod tests { use crate::OtelData; use opentelemetry::trace::{noop, SpanKind, TraceFlags}; use std::borrow::Cow; + use std::collections::HashMap; use std::sync::{Arc, Mutex}; use std::time::SystemTime; use tracing_subscriber::prelude::*; @@ -896,4 +919,80 @@ mod tests { assert!(keys.contains(&"idle_ns")); assert!(keys.contains(&"busy_ns")); } + + #[test] + fn records_error_fields() { + let tracer = TestTracer(Arc::new(Mutex::new(None))); + let subscriber = tracing_subscriber::registry().with(layer().with_tracer(tracer.clone())); + + use std::error::Error; + use std::fmt::Display; + + #[derive(Debug)] + struct DynError { + msg: &'static str, + source: Option>, + } + + impl Display for DynError { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}", self.msg) + } + } + impl Error for DynError { + fn source(&self) -> Option<&(dyn Error + 'static)> { + match &self.source { + Some(source) => Some(source), + None => None, + } + } + } + + let err = DynError { + msg: "user error", + source: Some(Box::new(DynError { + msg: "intermediate error", + source: Some(Box::new(DynError { + msg: "base error", + source: None, + })), + })), + }; + + tracing::subscriber::with_default(subscriber, || { + tracing::debug_span!( + "request", + error = &err as &(dyn std::error::Error + 'static) + ); + }); + + let attributes = tracer + .0 + .lock() + .unwrap() + .as_ref() + .unwrap() + .builder + .attributes + .as_ref() + .unwrap() + .clone(); + + let key_values = attributes + .into_iter() + .map(|attr| (attr.key.as_str().to_owned(), attr.value)) + .collect::>(); + + assert_eq!(key_values["error"].as_str(), "user error"); + assert_eq!( + key_values["error.chain"], + Value::Array( + vec![ + Cow::Borrowed("intermediate error"), + Cow::Borrowed("base error") + ] + .into() + ) + ); + } }