From 909fea608029099d1e175daf16f406d62a33f684 Mon Sep 17 00:00:00 2001 From: Joris Bayer Date: Tue, 4 Jun 2024 12:48:36 +0200 Subject: [PATCH] fix(spans): Do not trim essential fields (#3670) Since https://github.com/getsentry/relay/pull/3645, we're seeing incomplete or missing trace IDs on spans (see linked sentry issues). What happens is that after visiting a long `span.description`, there is no budget left for essential fields and the trimming processor drops or trims them. * Introduce `trim = "false"` field attribute to disallow trimming of specific fields. * Apply the new field to `span.trace_id` and other essential fields to prevent them from being partially scrubbed or dropped entirely. Current limitations: - Not trimming these fields leads to over-accepting bytes. This should not matter as long as the fields that have `trim = "false"` are limited in size (which they are currently not, see https://github.com/getsentry/relay/pull/3535 as follow-up). - The more correct solution would be to subtract the length of `trim = "false"` fields _before_ trimming any other fields. - Alternatively, we could decide to never over-accept, and drop items after visiting them if the budget is negative. I implemented this in [1136f76](https://github.com/getsentry/relay/pull/3670/commits/1136f76d983422fa2f4ae240197d7e43ef2b6435) but it resulted in more failing tests, because the current trimming processor already over-accepts a little bit (key lengths), and I did not want to touch the default behavior. cc @Dav1dde. Fixes [RELAY-2NY7](https://sentry.my.sentry.io/organizations/sentry/issues/1005495/), [RELAY-2NY8](https://sentry.my.sentry.io/organizations/sentry/issues/1005496/), [SNUBA-552](https://sentry.sentry.io/issues/5429321769/). --- CHANGELOG.md | 1 + relay-event-derive/src/lib.rs | 21 +++ .../src/normalize/mod.rs | 6 +- relay-event-normalization/src/trimming.rs | 151 ++++++++++++++++-- relay-event-schema/src/processor/attrs.rs | 3 + relay-event-schema/src/protocol/span.rs | 19 ++- .../src/protocol/span/convert.rs | 2 +- relay-protocol-derive/src/lib.rs | 2 +- ...t__tests__extract_span_metrics_mobile.snap | 22 +-- .../metrics_extraction/transactions/mod.rs | 2 +- relay-spans/src/span.rs | 2 +- 11 files changed, 193 insertions(+), 38 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fde78a73fd..f86b472075 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,7 @@ - Apply globally defined metric tags to legacy transaction metrics. ([#3615](https://github.com/getsentry/relay/pull/3615)) - Limit the maximum size of spans in an transaction to 800 kib. ([#3645](https://github.com/getsentry/relay/pull/3645)) - Scrub identifiers in spans with `op:db` and `db_system:redis`. ([#3642](https://github.com/getsentry/relay/pull/3642)) +- Stop trimming important span fields by marking them `trim = "false"`. ([#3670](https://github.com/getsentry/relay/pull/3670)) **Features**: diff --git a/relay-event-derive/src/lib.rs b/relay-event-derive/src/lib.rs index 0812bba1f7..814802af2b 100644 --- a/relay-event-derive/src/lib.rs +++ b/relay-event-derive/src/lib.rs @@ -323,6 +323,7 @@ struct FieldAttrs { max_chars_allowance: Option, max_depth: Option, max_bytes: Option, + trim: Option, } impl FieldAttrs { @@ -366,6 +367,14 @@ impl FieldAttrs { quote!(crate::processor::Pii::False) }; + let trim = if let Some(trim) = self.trim { + quote!(#trim) + } else if let Some(ref parent_attrs) = inherit_from_field_attrs { + quote!(#parent_attrs.trim) + } else { + quote!(true) + }; + let retain = self.retain; let max_chars = if let Some(ref max_chars) = self.max_chars { @@ -421,6 +430,7 @@ impl FieldAttrs { max_bytes: #max_bytes, pii: #pii, retain: #retain, + trim: #trim, } }) } @@ -595,6 +605,17 @@ fn parse_field_attributes( panic!("Got non string literal for retain"); } } + } else if ident == "trim" { + match name_value.lit { + Lit::Str(litstr) => match litstr.value().as_str() { + "true" => rv.trim = None, + "false" => rv.trim = Some(false), + other => panic!("Unknown value {other}"), + }, + _ => { + panic!("Got non string literal for trim"); + } + } } else if ident == "legacy_alias" || ident == "skip_serialization" { // Skip } else { diff --git a/relay-event-normalization/src/normalize/mod.rs b/relay-event-normalization/src/normalize/mod.rs index 57c43b4fa8..884c95ecbe 100644 --- a/relay-event-normalization/src/normalize/mod.rs +++ b/relay-event-normalization/src/normalize/mod.rs @@ -1706,7 +1706,6 @@ mod tests { timestamp: ~, start_timestamp: ~, exclusive_time: ~, - description: ~, op: "app_start_cold", span_id: ~, parent_span_id: ~, @@ -1714,6 +1713,7 @@ mod tests { segment_id: ~, is_segment: ~, status: ~, + description: ~, tags: ~, origin: ~, profile_id: ~, @@ -1751,7 +1751,6 @@ mod tests { timestamp: ~, start_timestamp: ~, exclusive_time: ~, - description: ~, op: "app.start.cold", span_id: ~, parent_span_id: ~, @@ -1759,6 +1758,7 @@ mod tests { segment_id: ~, is_segment: ~, status: ~, + description: ~, tags: ~, origin: ~, profile_id: ~, @@ -1796,7 +1796,6 @@ mod tests { timestamp: ~, start_timestamp: ~, exclusive_time: ~, - description: ~, op: "app.start.warm", span_id: ~, parent_span_id: ~, @@ -1804,6 +1803,7 @@ mod tests { segment_id: ~, is_segment: ~, status: ~, + description: ~, tags: ~, origin: ~, profile_id: ~, diff --git a/relay-event-normalization/src/trimming.rs b/relay-event-normalization/src/trimming.rs index dc210d6ed1..c5bb4a9ee1 100644 --- a/relay-event-normalization/src/trimming.rs +++ b/relay-event-normalization/src/trimming.rs @@ -74,15 +74,16 @@ impl Processor for TrimmingProcessor { }); } - if self.remaining_size() == Some(0) { - // TODO: Create remarks (ensure they do not bloat event) - return Err(ProcessingAction::DeleteValueHard); - } - if self.remaining_depth(state) == Some(0) { - // TODO: Create remarks (ensure they do not bloat event) - return Err(ProcessingAction::DeleteValueHard); + if state.attrs().trim { + if self.remaining_size() == Some(0) { + // TODO: Create remarks (ensure they do not bloat event) + return Err(ProcessingAction::DeleteValueHard); + } + if self.remaining_depth(state) == Some(0) { + // TODO: Create remarks (ensure they do not bloat event) + return Err(ProcessingAction::DeleteValueHard); + } } - Ok(()) } @@ -131,6 +132,10 @@ impl Processor for TrimmingProcessor { trim_string(value, meta, max_chars, state.attrs().max_chars_allowance); } + if !state.attrs().trim { + return Ok(()); + } + if let Some(size_state) = self.size_state.last() { if let Some(size_remaining) = size_state.size_remaining { trim_string(value, meta, size_remaining, 0); @@ -149,6 +154,10 @@ impl Processor for TrimmingProcessor { where T: ProcessValue, { + if !state.attrs().trim { + return Ok(()); + } + // If we need to check the bag size, then we go down a different path if !self.size_state.is_empty() { let original_length = value.len(); @@ -159,7 +168,7 @@ impl Processor for TrimmingProcessor { let mut split_index = None; for (index, item) in value.iter_mut().enumerate() { - if self.remaining_size().unwrap() == 0 { + if self.remaining_size() == Some(0) { split_index = Some(index); break; } @@ -191,6 +200,10 @@ impl Processor for TrimmingProcessor { where T: ProcessValue, { + if !state.attrs().trim { + return Ok(()); + } + // If we need to check the bag size, then we go down a different path if !self.size_state.is_empty() { let original_length = value.len(); @@ -201,7 +214,7 @@ impl Processor for TrimmingProcessor { let mut split_key = None; for (key, item) in value.iter_mut() { - if self.remaining_size().unwrap() == 0 { + if self.remaining_size() == Some(0) { split_key = Some(key.to_owned()); break; } @@ -230,6 +243,10 @@ impl Processor for TrimmingProcessor { _meta: &mut Meta, state: &ProcessingState<'_>, ) -> ProcessingResult { + if !state.attrs().trim { + return Ok(()); + } + match value { Value::Array(_) | Value::Object(_) => { if self.remaining_depth(state) == Some(1) { @@ -252,6 +269,10 @@ impl Processor for TrimmingProcessor { _meta: &mut Meta, state: &ProcessingState<'_>, ) -> ProcessingResult { + if !state.attrs().trim { + return Ok(()); + } + processor::apply(&mut stacktrace.frames, |frames, meta| { enforce_frame_hard_limit(frames, meta, 250); Ok(()) @@ -393,9 +414,10 @@ mod tests { use std::iter::repeat; use relay_event_schema::protocol::{ - Breadcrumb, Context, Contexts, Event, Exception, ExtraValue, Span, TagEntry, Tags, Values, + Breadcrumb, Context, Contexts, Event, Exception, ExtraValue, Span, SpanId, TagEntry, Tags, + TraceId, Values, }; - use relay_protocol::{Map, Remark, SerializableAnnotated}; + use relay_protocol::{get_value, Map, Remark, SerializableAnnotated}; use similar_asserts::assert_eq; use crate::MaxChars; @@ -930,4 +952,109 @@ mod tests { assert_eq!(event.0.unwrap().spans.0.unwrap().len(), 8); } + + #[test] + fn test_too_many_spans_trimmed_trace_id() { + let original_description = "a".repeat(819163); + let original_trace_id = TraceId("b".repeat(48)); + let mut event = Annotated::new(Event { + spans: Annotated::new(vec![ + Span { + description: original_description.clone().into(), + ..Default::default() + } + .into(), + Span { + trace_id: original_trace_id.clone().into(), + ..Default::default() + } + .into(), + ]), + ..Default::default() + }); + + let mut processor = TrimmingProcessor::new(); + processor::process_value(&mut event, &mut processor, ProcessingState::root()).unwrap(); + + assert_eq!( + get_value!(event.spans[0].description!), + &original_description + ); + // Trace ID would be trimmed without `trim = "false"` + assert_eq!(get_value!(event.spans[1].trace_id!), &original_trace_id); + } + + #[test] + fn test_too_many_spans_trimmed_trace_id_drop() { + let original_description = "a".repeat(819163); + let original_span_id = SpanId("b".repeat(48)); + let original_trace_id = TraceId("c".repeat(48)); + let original_segment_id = SpanId("d".repeat(48)); + let original_op = "e".repeat(129); + + let mut event = Annotated::new(Event { + spans: Annotated::new(vec![ + Span { + description: original_description.clone().into(), + ..Default::default() + } + .into(), + Span { + span_id: original_span_id.clone().into(), + trace_id: original_trace_id.clone().into(), + segment_id: original_segment_id.clone().into(), + is_segment: false.into(), + op: original_op.clone().into(), + ..Default::default() + } + .into(), + ]), + ..Default::default() + }); + + let mut processor = TrimmingProcessor::new(); + processor::process_value(&mut event, &mut processor, ProcessingState::root()).unwrap(); + + assert_eq!( + get_value!(event.spans[0].description!), + &original_description + ); + // These fields would be dropped without `trim = "false"` + assert_eq!(get_value!(event.spans[1].span_id!), &original_span_id); + assert_eq!(get_value!(event.spans[1].trace_id!), &original_trace_id); + assert_eq!(get_value!(event.spans[1].segment_id!), &original_segment_id); + assert_eq!(get_value!(event.spans[1].is_segment!), &false); + + // span.op is trimmed to its max_chars, but not dropped: + assert_eq!(get_value!(event.spans[1].op!).len(), 128); + } + + #[test] + fn test_trim_false_contributes_to_budget() { + for span_id in ["short", "looooooooooooooooooooooooooong"] { + let original_span_id = SpanId(span_id.to_owned()); + let original_description = "a".repeat(900000); + + let mut event = Annotated::new(Event { + spans: Annotated::new(vec![Span { + span_id: original_span_id.clone().into(), + description: original_description.clone().into(), + ..Default::default() + } + .into()]), + ..Default::default() + }); + + let mut processor = TrimmingProcessor::new(); + processor::process_value(&mut event, &mut processor, ProcessingState::root()).unwrap(); + + assert_eq!(get_value!(event.spans[0].span_id!).as_ref(), span_id); + + // The amount of trimming on the description depends on the length of the span id. + assert_eq!( + get_value!(event.spans[0].description!).len(), + 1024 * 800 - 12 - span_id.len(), + ); + } + } } diff --git a/relay-event-schema/src/processor/attrs.rs b/relay-event-schema/src/processor/attrs.rs index 5cfaa0beab..c80a9fe7c6 100644 --- a/relay-event-schema/src/processor/attrs.rs +++ b/relay-event-schema/src/processor/attrs.rs @@ -128,6 +128,8 @@ pub struct FieldAttrs { pub pii: Pii, /// Whether additional properties should be retained during normalization. pub retain: bool, + /// Whether the trimming processor is allowed to shorten or drop this field. + pub trim: bool, } /// A set of characters allowed or denied for a (string) field. @@ -167,6 +169,7 @@ impl FieldAttrs { max_bytes: None, pii: Pii::False, retain: false, + trim: true, } } diff --git a/relay-event-schema/src/protocol/span.rs b/relay-event-schema/src/protocol/span.rs index 08199c0f38..933d71f06d 100644 --- a/relay-event-schema/src/protocol/span.rs +++ b/relay-event-schema/src/protocol/span.rs @@ -26,37 +26,40 @@ pub struct Span { /// excluding its immediate child spans. pub exclusive_time: Annotated, - /// Human readable description of a span (e.g. method URL). - #[metastructure(pii = "maybe")] - pub description: Annotated, - /// Span type (see `OperationType` docs). - #[metastructure(max_chars = 128)] + #[metastructure(max_chars = 128, trim = "false")] pub op: Annotated, /// The Span id. - #[metastructure(required = "true")] + #[metastructure(required = "true", trim = "false")] pub span_id: Annotated, /// The ID of the span enclosing this span. + #[metastructure(trim = "false")] pub parent_span_id: Annotated, /// The ID of the trace the span belongs to. - #[metastructure(required = "true")] + #[metastructure(required = "true", trim = "false")] pub trace_id: Annotated, /// A unique identifier for a segment within a trace (8 byte hexadecimal string). /// /// For spans embedded in transactions, the `segment_id` is the `span_id` of the containing /// transaction. + #[metastructure(trim = "false")] pub segment_id: Annotated, /// Whether or not the current span is the root of the segment. + #[metastructure(trim = "false")] pub is_segment: Annotated, /// The status of a span. pub status: Annotated, + /// Human readable description of a span (e.g. method URL). + #[metastructure(pii = "maybe")] + pub description: Annotated, + /// Arbitrary tags on a span, like on the top-level event. #[metastructure(pii = "maybe")] pub tags: Annotated>, @@ -450,11 +453,11 @@ mod tests { "timestamp": 0.0, "start_timestamp": -63158400.0, "exclusive_time": 1.23, - "description": "desc", "op": "operation", "span_id": "fa90fdead5f74052", "trace_id": "4c79f60c11214eb38604f4ae0781bfb2", "status": "ok", + "description": "desc", "origin": "auto.http", "measurements": { "memory": { diff --git a/relay-event-schema/src/protocol/span/convert.rs b/relay-event-schema/src/protocol/span/convert.rs index 1246e3c649..d283c2acd6 100644 --- a/relay-event-schema/src/protocol/span/convert.rs +++ b/relay-event-schema/src/protocol/span/convert.rs @@ -248,7 +248,6 @@ mod tests { timestamp: ~, start_timestamp: ~, exclusive_time: 123.4, - description: "my 1st transaction", op: "myop", span_id: SpanId( "fa90fdead5f74052", @@ -264,6 +263,7 @@ mod tests { ), is_segment: true, status: Ok, + description: "my 1st transaction", tags: ~, origin: "manual", profile_id: EventId( diff --git a/relay-protocol-derive/src/lib.rs b/relay-protocol-derive/src/lib.rs index 4fb7be5959..11f9b2d6ab 100644 --- a/relay-protocol-derive/src/lib.rs +++ b/relay-protocol-derive/src/lib.rs @@ -730,7 +730,7 @@ fn parse_field_attributes( rv.skip_serialization = FromStr::from_str(&litstr.value()) .expect("Unknown value for skip_serialization"); } - _ => panic!("Got non string literal for legacy_alias"), + _ => panic!("Got non string literal for skip_serialization"), } } } diff --git a/relay-server/src/metrics_extraction/snapshots/relay_server__metrics_extraction__event__tests__extract_span_metrics_mobile.snap b/relay-server/src/metrics_extraction/snapshots/relay_server__metrics_extraction__event__tests__extract_span_metrics_mobile.snap index 954b08971b..48ef885df0 100644 --- a/relay-server/src/metrics_extraction/snapshots/relay_server__metrics_extraction__event__tests__extract_span_metrics_mobile.snap +++ b/relay-server/src/metrics_extraction/snapshots/relay_server__metrics_extraction__event__tests__extract_span_metrics_mobile.snap @@ -12,7 +12,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 2000.0, - description: ~, op: "app.start.cold", span_id: SpanId( "bd429c44b67a3eb4", @@ -24,6 +23,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: ~, tags: ~, origin: ~, profile_id: ~, @@ -60,7 +60,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: ~, op: "ui.load.initial_display", span_id: SpanId( "bd429c44b67a3eb2", @@ -72,6 +71,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: ~, tags: ~, origin: ~, profile_id: ~, @@ -185,7 +185,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "Cold Start", op: "app.start.cold", span_id: SpanId( "bd429c44b67a3eb2", @@ -197,6 +196,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "Cold Start", tags: ~, origin: ~, profile_id: ~, @@ -235,7 +235,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "Custom Op", op: "custom.op", span_id: SpanId( "bd429c44b67a3eb2", @@ -247,6 +246,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "Custom Op", tags: ~, origin: ~, profile_id: ~, @@ -282,7 +282,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "io.sentry.android.core.SentryPerformanceProvider.onCreate", op: "contentprovider.load", span_id: SpanId( "bd429c44b67a3eb2", @@ -294,6 +293,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "io.sentry.android.core.SentryPerformanceProvider.onCreate", tags: ~, origin: ~, profile_id: ~, @@ -331,7 +331,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "io.sentry.samples.android.MyApplication.onCreate", op: "application.load", span_id: SpanId( "bd429c44b67a3eb2", @@ -343,6 +342,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "io.sentry.samples.android.MyApplication.onCreate", tags: ~, origin: ~, profile_id: ~, @@ -380,7 +380,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "io.sentry.samples.android.MainActivity.onCreate", op: "activity.load", span_id: SpanId( "bd429c44b67a3eb2", @@ -392,6 +391,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "io.sentry.samples.android.MainActivity.onCreate", tags: ~, origin: ~, profile_id: ~, @@ -480,7 +480,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "Process Initialization", op: "process.load", span_id: SpanId( "bd429c44b67a3eb2", @@ -492,6 +491,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "Process Initialization", tags: ~, origin: ~, profile_id: ~, @@ -578,7 +578,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "somebackup.212321", op: "file.read", span_id: SpanId( "bd429c44b67a3eb2", @@ -590,6 +589,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "somebackup.212321", tags: ~, origin: ~, profile_id: ~, @@ -628,7 +628,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "www.example.com", op: "http.client", span_id: SpanId( "bd429c44b67a3eb2", @@ -640,6 +639,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "www.example.com", tags: ~, origin: ~, profile_id: ~, @@ -728,7 +728,6 @@ expression: "(&event.value().unwrap().spans, metrics)" 2020-08-21T02:18:20Z, ), exclusive_time: 3000.0, - description: "www.example.com", op: "http.client", span_id: SpanId( "bd429c44b67a3eb2", @@ -740,6 +739,7 @@ expression: "(&event.value().unwrap().spans, metrics)" segment_id: ~, is_segment: ~, status: ~, + description: "www.example.com", tags: ~, origin: ~, profile_id: ~, diff --git a/relay-server/src/metrics_extraction/transactions/mod.rs b/relay-server/src/metrics_extraction/transactions/mod.rs index ed397df4da..08d919796e 100644 --- a/relay-server/src/metrics_extraction/transactions/mod.rs +++ b/relay-server/src/metrics_extraction/transactions/mod.rs @@ -632,7 +632,6 @@ mod tests { 2020-08-21T02:18:20Z, ), exclusive_time: 2000.0, - description: "", op: "react.mount", span_id: SpanId( "bd429c44b67a3eb4", @@ -646,6 +645,7 @@ mod tests { segment_id: ~, is_segment: ~, status: ~, + description: "", tags: ~, origin: ~, profile_id: ~, diff --git a/relay-spans/src/span.rs b/relay-spans/src/span.rs index d043efbbf1..507e868f56 100644 --- a/relay-spans/src/span.rs +++ b/relay-spans/src/span.rs @@ -602,7 +602,6 @@ mod tests { 1970-01-01T00:02:03Z, ), exclusive_time: 500.0, - description: ~, op: "myop", span_id: SpanId( "fa90fdead5f74052", @@ -618,6 +617,7 @@ mod tests { ), is_segment: ~, status: Ok, + description: ~, tags: ~, origin: ~, profile_id: EventId(