feat(suspect-spans): Add span exclusive time

CHANGELOG.md

@@ -14,6 +14,7 @@
 **Internal**:
 
 - Add new metrics on Relay's performance in dealing with buckets of metric aggregates, as well as the amount of aggregated buckets. ([#1070](https://github.com/getsentry/relay/pull/1070))
+- Add the exclusive time of a span. ([#1061](https://github.com/getsentry/relay/pull/1061))
 
 ## 21.8.0
 

relay-general/src/protocol/contexts.rs

@@ -442,7 +442,7 @@ impl FromValue for TraceId {
 }
 
 /// A 16-character hex string as described in the W3C trace context spec.
-#[derive(Clone, Debug, Default, PartialEq, Empty, IntoValue, ProcessValue)]
+#[derive(Clone, Debug, Default, Eq, Hash, PartialEq, Empty, IntoValue, ProcessValue)]
 #[cfg_attr(feature = "jsonschema", derive(JsonSchema))]
 pub struct SpanId(pub String);
 

relay-general/src/protocol/span.rs

@@ -13,6 +13,10 @@ pub struct Span {
     #[metastructure(required = "true")]
     pub start_timestamp: Annotated<Timestamp>,
 
+    /// The amount of time in milliseconds spent in this span,
+    /// excluding its immediate child spans.
+    pub exclusive_time: Annotated<f64>,
+
     /// Human readable description of a span (e.g. method URL).
     #[metastructure(pii = "maybe")]
     pub description: Annotated<String>,
@@ -59,6 +63,7 @@ mod tests {
         let json = r#"{
   "timestamp": 0.0,
   "start_timestamp": -63158400.0,
+  "exclusive_time": 1.23,
   "description": "desc",
   "op": "operation",
   "span_id": "fa90fdead5f74052",
@@ -69,6 +74,7 @@ mod tests {
         let span = Annotated::new(Span {
             timestamp: Annotated::new(Utc.ymd(1970, 1, 1).and_hms_nano(0, 0, 0, 0).into()),
             start_timestamp: Annotated::new(Utc.ymd(1968, 1, 1).and_hms_nano(0, 0, 0, 0).into()),
+            exclusive_time: Annotated::new(1.23),
             description: Annotated::new("desc".to_owned()),
             op: Annotated::new("operation".to_owned()),
             trace_id: Annotated::new(TraceId("4c79f60c11214eb38604f4ae0781bfb2".into())),

relay-general/src/store/mod.rs

@@ -1,4 +1,5 @@
 //! Utility code for sentry's internal store.
+use std::collections::BTreeSet;
 use std::sync::Arc;
 
 use chrono::{DateTime, Utc};
@@ -7,7 +8,7 @@ use serde_json::Value;
 
 use crate::processor::{ProcessingState, Processor};
 use crate::protocol::{Event, IpAddr};
-use crate::types::{Meta, ProcessingResult};
+use crate::types::{Meta, ProcessingResult, SpanAttribute};
 
 mod clock_drift;
 mod event_error;
@@ -53,6 +54,9 @@ pub struct StoreConfig {
 
     /// Emit breakdowns based on given configuration.
     pub breakdowns: Option<normalize::breakdowns::BreakdownsConfig>,
+
+    /// Emit additional span attributes based on given configuration.
+    pub span_attributes: BTreeSet<SpanAttribute>,
 }
 
 /// The processor that normalizes events for store.

relay-general/src/store/normalize.rs

@@ -26,6 +26,7 @@ mod contexts;
 mod logentry;
 mod mechanism;
 mod request;
+mod spans;
 mod stacktrace;
 
 #[cfg(feature = "uaparser")]
@@ -111,6 +112,12 @@ impl<'a> NormalizeProcessor<'a> {
         }
     }
 
+    fn normalize_spans(&self, event: &mut Event) {
+        if event.ty.value() == Some(&EventType::Transaction) {
+            spans::normalize_spans(event, &self.config.span_attributes);
+        }
+    }
+
     /// Ensures that the `release` and `dist` fields match up.
     fn normalize_release_dist(&self, event: &mut Event) {
         if event.dist.value().is_some() && event.release.value().is_empty() {
@@ -493,6 +500,7 @@ impl<'a> Processor for NormalizeProcessor<'a> {
         self.normalize_user_agent(event);
         self.normalize_measurements(event);
         self.normalize_breakdowns(event);
+        self.normalize_spans(event);
 
         Ok(())
     }

relay-general/src/store/normalize/breakdowns.rs

@@ -11,29 +11,25 @@ use crate::protocol::{Breakdowns, Event, Measurement, Measurements, Timestamp};
 use crate::types::Annotated;
 
 #[derive(Clone, Debug)]
-struct TimeWindowSpan {
-    start_timestamp: Timestamp,
-    end_timestamp: Timestamp,
+pub struct TimeWindowSpan {
+    pub start: Timestamp,
+    pub end: Timestamp,
 }
 
 impl TimeWindowSpan {
-    fn new(start_timestamp: Timestamp, end_timestamp: Timestamp) -> Self {
-        if end_timestamp < start_timestamp {
+    pub fn new(start: Timestamp, end: Timestamp) -> Self {
+        if end < start {
             return TimeWindowSpan {
-                start_timestamp: end_timestamp,
-                end_timestamp: start_timestamp,
+                start: end,
+                end: start,
             };
         }
 
-        TimeWindowSpan {
-            start_timestamp,
-            end_timestamp,
-        }
+        TimeWindowSpan { start, end }
     }
 
-    fn get_duration(&self) -> f64 {
-        let delta: f64 =
-            (self.end_timestamp.timestamp_nanos() - self.start_timestamp.timestamp_nanos()) as f64;
+    pub fn duration(&self) -> f64 {
+        let delta: f64 = (self.end.timestamp_nanos() - self.start.timestamp_nanos()) as f64;
         // convert to milliseconds (1 ms = 1,000,000 nanoseconds)
         (delta / 1_000_000.00).abs()
     }
@@ -50,29 +46,28 @@ fn get_op_time_spent(mut intervals: Vec<TimeWindowSpan>) -> Option<f64> {
         return None;
     }
 
-    // sort by start_timestamp in ascending order
-    intervals.sort_unstable_by_key(|span| span.start_timestamp);
+    // sort by start timestamp in ascending order
+    intervals.sort_unstable_by_key(|span| span.start);
 
     let mut op_time_spent = 0.0;
     let mut previous_interval: Option<TimeWindowSpan> = None;
 
     for current_interval in intervals.into_iter() {
         match previous_interval.as_mut() {
             Some(last_interval) => {
-                if last_interval.end_timestamp < current_interval.start_timestamp {
+                if last_interval.end < current_interval.start {
                     // if current_interval does not overlap with last_interval,
                     // then add last_interval to op_time_spent
-                    op_time_spent += last_interval.get_duration();
+                    op_time_spent += last_interval.duration();
                     previous_interval = Some(current_interval);
                     continue;
                 }
 
                 // current_interval and last_interval overlaps; so we merge these intervals
 
-                // invariant: last_interval.start_timestamp <= current_interval.start_timestamp
+                // invariant: last_interval.start <= current_interval.start
 
-                last_interval.end_timestamp =
-                    std::cmp::max(last_interval.end_timestamp, current_interval.end_timestamp);
+                last_interval.end = std::cmp::max(last_interval.end, current_interval.end);
             }
             None => {
                 previous_interval = Some(current_interval);
@@ -81,7 +76,7 @@ fn get_op_time_spent(mut intervals: Vec<TimeWindowSpan>) -> Option<f64> {
     }
 
     if let Some(remaining_interval) = previous_interval {
-        op_time_spent += remaining_interval.get_duration();
+        op_time_spent += remaining_interval.duration();
     }
 
     Some(op_time_spent)
@@ -129,17 +124,17 @@ impl EmitBreakdowns for SpanOperationsConfig {
                 Some(span_op) => span_op,
             };
 
-            let start_timestamp = match span.start_timestamp.value() {
+            let start = match span.start_timestamp.value() {
                 None => continue,
-                Some(start_timestamp) => start_timestamp,
+                Some(start) => start,
             };
 
-            let end_timestamp = match span.timestamp.value() {
+            let end = match span.timestamp.value() {
                 None => continue,
-                Some(end_timestamp) => end_timestamp,
+                Some(end) => end,
             };
 
-            let cover = TimeWindowSpan::new(*start_timestamp, *end_timestamp);
+            let cover = TimeWindowSpan::new(*start, *end);
 
             // Only emit an operation breakdown measurement if the operation name matches any
             // entries in operation_name_breakdown.
@@ -316,13 +311,13 @@ mod tests {
     #[test]
     fn test_emit_ops_breakdown() {
         fn make_span(
-            start_timestamp: Annotated<Timestamp>,
-            end_timestamp: Annotated<Timestamp>,
+            start: Annotated<Timestamp>,
+            end: Annotated<Timestamp>,
             op_name: String,
         ) -> Annotated<Span> {
             Annotated::new(Span {
-                timestamp: end_timestamp,
-                start_timestamp,
+                timestamp: end,
+                start_timestamp: start,
                 description: Annotated::new("desc".to_owned()),
                 op: Annotated::new(op_name),
                 trace_id: Annotated::new(TraceId("4c79f60c11214eb38604f4ae0781bfb2".into())),