relay_event_normalization/normalize/span/
exclusive_time.rs

1//! Span attribute materialization.
2
3use std::collections::HashMap;
4use std::time::Duration;
5
6use relay_event_schema::protocol::{Contexts, Event, Span, SpanId, TraceContext};
7use relay_protocol::Annotated;
8
9use crate::normalize::breakdowns::TimeWindowSpan;
10
11/// Computes the exclusive time of the source interval after subtracting the
12/// list of intervals.
13///
14/// Assumes that the input intervals are sorted by start time.
15fn interval_exclusive_time(mut parent: TimeWindowSpan, intervals: &[TimeWindowSpan]) -> Duration {
16    let mut exclusive_time = Duration::new(0, 0);
17
18    for interval in intervals {
19        // Exit early to avoid adding zeros
20        if interval.start >= parent.end {
21            break;
22        }
23
24        // Add time in the parent before the start of the current interval to the exclusive time
25        if let Ok(start_offset) = (interval.start - parent.start).to_std() {
26            exclusive_time += start_offset;
27        }
28
29        parent.start = interval.end.clamp(parent.start, parent.end);
30    }
31
32    // Add the remaining duration after the last interval ended
33    exclusive_time + parent.duration()
34}
35
36fn set_event_exclusive_time(
37    event_interval: TimeWindowSpan,
38    contexts: &mut Contexts,
39    span_map: &HashMap<SpanId, Vec<TimeWindowSpan>>,
40) {
41    let Some(trace_context) = contexts.get_mut::<TraceContext>() else {
42        return;
43    };
44
45    if trace_context.exclusive_time.value().is_some() {
46        // Exclusive time already set, respect it.
47        return;
48    }
49
50    let Some(span_id) = trace_context.span_id.value() else {
51        return;
52    };
53
54    let child_intervals = span_map
55        .get(span_id)
56        .map(|vec| vec.as_slice())
57        .unwrap_or_default();
58
59    let exclusive_time = interval_exclusive_time(event_interval, child_intervals);
60    trace_context.exclusive_time =
61        Annotated::new(relay_common::time::duration_to_millis(exclusive_time));
62}
63
64fn set_span_exclusive_time(
65    span: &mut Annotated<Span>,
66    span_map: &HashMap<SpanId, Vec<TimeWindowSpan>>,
67) {
68    let span = match span.value_mut() {
69        None => return,
70        Some(span) => span,
71    };
72
73    let span_id = match span.span_id.value() {
74        None => return,
75        Some(span_id) => span_id,
76    };
77
78    let span_interval = match (span.start_timestamp.value(), span.timestamp.value()) {
79        (Some(start), Some(end)) => TimeWindowSpan::new(*start, *end),
80        _ => return,
81    };
82
83    let child_intervals = span_map
84        .get(span_id)
85        .map(|vec| vec.as_slice())
86        .unwrap_or_default();
87
88    let exclusive_time = interval_exclusive_time(span_interval, child_intervals);
89    span.exclusive_time = Annotated::new(relay_common::time::duration_to_millis(exclusive_time));
90}
91
92/// Computes the exclusive time for all spans in the event.
93pub fn compute_span_exclusive_time(event: &mut Event) {
94    let contexts = match event.contexts.value_mut() {
95        Some(contexts) => contexts,
96        _ => return,
97    };
98
99    let event_interval = match (event.start_timestamp.value(), event.timestamp.value()) {
100        (Some(start), Some(end)) => TimeWindowSpan::new(*start, *end),
101        _ => return,
102    };
103
104    let spans = event.spans.value_mut().get_or_insert_with(Vec::new);
105
106    let mut span_map = HashMap::new();
107    for span in spans.iter() {
108        let span = match span.value() {
109            None => continue,
110            Some(span) => span,
111        };
112
113        let Some(&parent_span_id) = span.parent_span_id.value() else {
114            continue;
115        };
116
117        let interval = match (span.start_timestamp.value(), span.timestamp.value()) {
118            (Some(start), Some(end)) => TimeWindowSpan::new(*start, *end),
119            _ => continue,
120        };
121
122        span_map
123            .entry(parent_span_id)
124            .or_insert_with(Vec::new)
125            .push(interval)
126    }
127
128    // Sort intervals to fulfill precondition of `interval_exclusive_time`
129    for intervals in span_map.values_mut() {
130        intervals.sort_unstable_by_key(|interval| interval.start);
131    }
132
133    set_event_exclusive_time(event_interval, contexts, &span_map);
134
135    for span in spans.iter_mut() {
136        set_span_exclusive_time(span, &span_map);
137    }
138}
139
140#[cfg(test)]
141mod tests {
142    use chrono::{TimeZone, Utc};
143    use relay_event_schema::protocol::{EventType, Timestamp};
144    use similar_asserts::assert_eq;
145
146    use super::*;
147
148    fn make_event(
149        start: Timestamp,
150        end: Timestamp,
151        span_id: &str,
152        spans: Vec<Annotated<Span>>,
153    ) -> Event {
154        Event {
155            ty: EventType::Transaction.into(),
156            start_timestamp: Annotated::new(start),
157            timestamp: Annotated::new(end),
158            contexts: {
159                let mut contexts = Contexts::new();
160                contexts.add(TraceContext {
161                    trace_id: Annotated::new("4c79f60c11214eb38604f4ae0781bfb2".parse().unwrap()),
162                    span_id: Annotated::new(span_id.parse().unwrap()),
163                    ..Default::default()
164                });
165                Annotated::new(contexts)
166            },
167            spans: spans.into(),
168            ..Default::default()
169        }
170    }
171
172    fn make_span(
173        op: &str,
174        description: &str,
175        start: Timestamp,
176        end: Timestamp,
177        span_id: &str,
178        parent_span_id: &str,
179    ) -> Annotated<Span> {
180        Annotated::new(Span {
181            op: Annotated::new(op.into()),
182            description: Annotated::new(description.into()),
183            start_timestamp: Annotated::new(start),
184            timestamp: Annotated::new(end),
185            trace_id: Annotated::new("4c79f60c11214eb38604f4ae0781bfb2".parse().unwrap()),
186            span_id: Annotated::new(span_id.parse().unwrap()),
187            parent_span_id: Annotated::new(parent_span_id.parse().unwrap()),
188            ..Default::default()
189        })
190    }
191
192    fn extract_exclusive_time(span: &Span) -> (&SpanId, f64) {
193        (
194            span.span_id.value().unwrap(),
195            *span.exclusive_time.value().unwrap(),
196        )
197    }
198
199    fn extract_span_exclusive_times(event: &Event) -> HashMap<&SpanId, f64> {
200        let spans = event.spans.value().unwrap();
201        let mut exclusive_times: HashMap<_, _> = spans
202            .iter()
203            .filter_map(Annotated::value)
204            .map(extract_exclusive_time)
205            .collect();
206
207        let trace_context = event.context::<TraceContext>().unwrap();
208        let transaction_span_id = trace_context.span_id.value().unwrap();
209        let transaction_exclusive_time = *trace_context.exclusive_time.value().unwrap();
210        exclusive_times.insert(transaction_span_id, transaction_exclusive_time);
211
212        exclusive_times
213    }
214
215    #[test]
216    fn test_childless_spans() {
217        let mut event = make_event(
218            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
219            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
220            "aaaaaaaaaaaaaaaa",
221            vec![
222                make_span(
223                    "db",
224                    "SELECT * FROM table;",
225                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
226                    Utc.timestamp_opt(1609455604, 0).unwrap().into(),
227                    "bbbbbbbbbbbbbbbb",
228                    "aaaaaaaaaaaaaaaa",
229                ),
230                make_span(
231                    "db",
232                    "SELECT * FROM table;",
233                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
234                    Utc.timestamp_opt(1609455603, 500_000_000).unwrap().into(),
235                    "cccccccccccccccc",
236                    "aaaaaaaaaaaaaaaa",
237                ),
238                make_span(
239                    "db",
240                    "SELECT * FROM table;",
241                    Utc.timestamp_opt(1609455603, 0).unwrap().into(),
242                    Utc.timestamp_opt(1609455604, 877_000_000).unwrap().into(),
243                    "dddddddddddddddd",
244                    "aaaaaaaaaaaaaaaa",
245                ),
246            ],
247        );
248
249        compute_span_exclusive_time(&mut event);
250
251        assert_eq!(
252            extract_span_exclusive_times(&event),
253            HashMap::from_iter([
254                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 1123.0),
255                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 3000.0),
256                (&"cccccccccccccccc".parse().unwrap(), 2500.0),
257                (&"dddddddddddddddd".parse().unwrap(), 1877.0)
258            ]),
259        );
260    }
261
262    #[test]
263    fn test_nested_spans() {
264        let mut event = make_event(
265            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
266            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
267            "aaaaaaaaaaaaaaaa",
268            vec![
269                make_span(
270                    "db",
271                    "SELECT * FROM table;",
272                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
273                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
274                    "bbbbbbbbbbbbbbbb",
275                    "aaaaaaaaaaaaaaaa",
276                ),
277                make_span(
278                    "db",
279                    "SELECT * FROM table;",
280                    Utc.timestamp_opt(1609455601, 200_000_000).unwrap().into(),
281                    Utc.timestamp_opt(1609455601, 800_000_000).unwrap().into(),
282                    "cccccccccccccccc",
283                    "bbbbbbbbbbbbbbbb",
284                ),
285                make_span(
286                    "db",
287                    "SELECT * FROM table;",
288                    Utc.timestamp_opt(1609455601, 400_000_000).unwrap().into(),
289                    Utc.timestamp_opt(1609455601, 600_000_000).unwrap().into(),
290                    "dddddddddddddddd",
291                    "cccccccccccccccc",
292                ),
293            ],
294        );
295
296        compute_span_exclusive_time(&mut event);
297
298        assert_eq!(
299            extract_span_exclusive_times(&event),
300            HashMap::from_iter([
301                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
302                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 400.0),
303                (&"cccccccccccccccc".parse().unwrap(), 400.0),
304                (&"dddddddddddddddd".parse().unwrap(), 200.0),
305            ])
306        );
307    }
308
309    #[test]
310    fn test_overlapping_child_spans() {
311        let mut event = make_event(
312            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
313            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
314            "aaaaaaaaaaaaaaaa",
315            vec![
316                make_span(
317                    "db",
318                    "SELECT * FROM table;",
319                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
320                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
321                    "bbbbbbbbbbbbbbbb",
322                    "aaaaaaaaaaaaaaaa",
323                ),
324                make_span(
325                    "db",
326                    "SELECT * FROM table;",
327                    Utc.timestamp_opt(1609455601, 200_000_000).unwrap().into(),
328                    Utc.timestamp_opt(1609455601, 600_000_000).unwrap().into(),
329                    "cccccccccccccccc",
330                    "bbbbbbbbbbbbbbbb",
331                ),
332                make_span(
333                    "db",
334                    "SELECT * FROM table;",
335                    Utc.timestamp_opt(1609455601, 400_000_000).unwrap().into(),
336                    Utc.timestamp_opt(1609455601, 800_000_000).unwrap().into(),
337                    "dddddddddddddddd",
338                    "bbbbbbbbbbbbbbbb",
339                ),
340            ],
341        );
342
343        compute_span_exclusive_time(&mut event);
344
345        assert_eq!(
346            extract_span_exclusive_times(&event),
347            HashMap::from_iter([
348                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
349                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 400.0),
350                (&"cccccccccccccccc".parse().unwrap(), 400.0),
351                (&"dddddddddddddddd".parse().unwrap(), 400.0),
352            ])
353        );
354    }
355
356    #[test]
357    fn test_child_spans_dont_intersect_parent() {
358        let mut event = make_event(
359            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
360            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
361            "aaaaaaaaaaaaaaaa",
362            vec![
363                make_span(
364                    "db",
365                    "SELECT * FROM table;",
366                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
367                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
368                    "bbbbbbbbbbbbbbbb",
369                    "aaaaaaaaaaaaaaaa",
370                ),
371                make_span(
372                    "db",
373                    "SELECT * FROM table;",
374                    Utc.timestamp_opt(1609455600, 400_000_000).unwrap().into(),
375                    Utc.timestamp_opt(1609455600, 800_000_000).unwrap().into(),
376                    "cccccccccccccccc",
377                    "bbbbbbbbbbbbbbbb",
378                ),
379                make_span(
380                    "db",
381                    "SELECT * FROM table;",
382                    Utc.timestamp_opt(1609455602, 200_000_000).unwrap().into(),
383                    Utc.timestamp_opt(1609455602, 600_000_000).unwrap().into(),
384                    "dddddddddddddddd",
385                    "bbbbbbbbbbbbbbbb",
386                ),
387            ],
388        );
389
390        compute_span_exclusive_time(&mut event);
391
392        assert_eq!(
393            extract_span_exclusive_times(&event),
394            HashMap::from_iter([
395                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
396                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 1000.0),
397                (&"cccccccccccccccc".parse().unwrap(), 400.0),
398                (&"dddddddddddddddd".parse().unwrap(), 400.0),
399            ])
400        );
401    }
402
403    #[test]
404    fn test_child_spans_extend_beyond_parent() {
405        let mut event = make_event(
406            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
407            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
408            "aaaaaaaaaaaaaaaa",
409            vec![
410                make_span(
411                    "db",
412                    "SELECT * FROM table;",
413                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
414                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
415                    "bbbbbbbbbbbbbbbb",
416                    "aaaaaaaaaaaaaaaa",
417                ),
418                make_span(
419                    "db",
420                    "SELECT * FROM table;",
421                    Utc.timestamp_opt(1609455600, 800_000_000).unwrap().into(),
422                    Utc.timestamp_opt(1609455601, 400_000_000).unwrap().into(),
423                    "cccccccccccccccc",
424                    "bbbbbbbbbbbbbbbb",
425                ),
426                make_span(
427                    "db",
428                    "SELECT * FROM table;",
429                    Utc.timestamp_opt(1609455601, 600_000_000).unwrap().into(),
430                    Utc.timestamp_opt(1609455602, 200_000_000).unwrap().into(),
431                    "dddddddddddddddd",
432                    "bbbbbbbbbbbbbbbb",
433                ),
434            ],
435        );
436
437        compute_span_exclusive_time(&mut event);
438
439        assert_eq!(
440            extract_span_exclusive_times(&event),
441            HashMap::from_iter([
442                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
443                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 200.0),
444                (&"cccccccccccccccc".parse().unwrap(), 600.0),
445                (&"dddddddddddddddd".parse().unwrap(), 600.0),
446            ])
447        );
448    }
449
450    #[test]
451    fn test_child_spans_consumes_all_of_parent() {
452        let mut event = make_event(
453            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
454            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
455            "aaaaaaaaaaaaaaaa",
456            vec![
457                make_span(
458                    "db",
459                    "SELECT * FROM table;",
460                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
461                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
462                    "bbbbbbbbbbbbbbbb",
463                    "aaaaaaaaaaaaaaaa",
464                ),
465                make_span(
466                    "db",
467                    "SELECT * FROM table;",
468                    Utc.timestamp_opt(1609455600, 800_000_000).unwrap().into(),
469                    Utc.timestamp_opt(1609455601, 600_000_000).unwrap().into(),
470                    "cccccccccccccccc",
471                    "bbbbbbbbbbbbbbbb",
472                ),
473                make_span(
474                    "db",
475                    "SELECT * FROM table;",
476                    Utc.timestamp_opt(1609455601, 400_000_000).unwrap().into(),
477                    Utc.timestamp_opt(1609455602, 200_000_000).unwrap().into(),
478                    "dddddddddddddddd",
479                    "bbbbbbbbbbbbbbbb",
480                ),
481            ],
482        );
483
484        compute_span_exclusive_time(&mut event);
485
486        assert_eq!(
487            extract_span_exclusive_times(&event),
488            HashMap::from_iter([
489                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
490                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 0.0),
491                (&"cccccccccccccccc".parse().unwrap(), 800.0),
492                (&"dddddddddddddddd".parse().unwrap(), 800.0),
493            ])
494        );
495    }
496
497    #[test]
498    fn test_only_immediate_child_spans_affect_calculation() {
499        let mut event = make_event(
500            Utc.timestamp_opt(1609455600, 0).unwrap().into(),
501            Utc.timestamp_opt(1609455605, 0).unwrap().into(),
502            "aaaaaaaaaaaaaaaa",
503            vec![
504                make_span(
505                    "db",
506                    "SELECT * FROM table;",
507                    Utc.timestamp_opt(1609455601, 0).unwrap().into(),
508                    Utc.timestamp_opt(1609455602, 0).unwrap().into(),
509                    "bbbbbbbbbbbbbbbb",
510                    "aaaaaaaaaaaaaaaa",
511                ),
512                make_span(
513                    "db",
514                    "SELECT * FROM table;",
515                    Utc.timestamp_opt(1609455601, 600_000_000).unwrap().into(),
516                    Utc.timestamp_opt(1609455602, 200_000_000).unwrap().into(),
517                    "cccccccccccccccc",
518                    "bbbbbbbbbbbbbbbb",
519                ),
520                // this should only affect the calculation for it's immediate parent
521                // which is `cccccccccccccccc` and not `bbbbbbbbbbbbbbbb`
522                make_span(
523                    "db",
524                    "SELECT * FROM table;",
525                    Utc.timestamp_opt(1609455601, 400_000_000).unwrap().into(),
526                    Utc.timestamp_opt(1609455601, 800_000_000).unwrap().into(),
527                    "dddddddddddddddd",
528                    "cccccccccccccccc",
529                ),
530            ],
531        );
532
533        compute_span_exclusive_time(&mut event);
534
535        assert_eq!(
536            extract_span_exclusive_times(&event),
537            HashMap::from_iter([
538                (&"aaaaaaaaaaaaaaaa".parse().unwrap(), 4000.0),
539                (&"bbbbbbbbbbbbbbbb".parse().unwrap(), 600.0),
540                (&"cccccccccccccccc".parse().unwrap(), 400.0),
541                (&"dddddddddddddddd".parse().unwrap(), 400.0),
542            ])
543        );
544    }
545}
relay_event_normalization/normalize/span/exclusive_time.rs

relay_event_normalization/normalize/span/
exclusive_time.rs
