Skip to content

Commit 0210399

Browse files
Dav1ddeDav1dde
authored
ref(logs): Uses the received timestamp as observed nanos (#4810)
Uses the received time instead of the current time for the observed timestamp.
1 parent e16a483 commit 0210399

File tree

3 files changed

+49
-91
lines changed

3 files changed

+49
-91
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@
2424
- Consistently always emit session outcomes. ([#4798](https://github.com/getsentry/relay/pull/4798))
2525
- Set default sdk name for playstation crashes. ([#4802](https://github.com/getsentry/relay/pull/4802))
2626
- Skip large attachments on playstation crashes. ([#4793](https://github.com/getsentry/relay/pull/4793))
27+
- Use the received timestamp as observed nanos for logs. ([#4810](https://github.com/getsentry/relay/pull/4810))
2728

2829
## 25.5.1
2930

‎relay-ourlogs/src/ourlog.rs‎

Lines changed: 45 additions & 89 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
use chrono::{TimeZone, Utc};
1+
use chrono::{DateTime, TimeZone, Utc};
22
use opentelemetry_proto::tonic::common::v1::any_value::Value as OtelValue;
33

44
use crate::OtelLog;
@@ -24,7 +24,7 @@ fn otel_value_to_log_attribute(value: OtelValue) -> Option<Attribute> {
2424
}
2525

2626
/// Transform an OtelLog to a Sentry log.
27-
pub fn otel_to_sentry_log(otel_log: OtelLog) -> Result<OurLog, Error> {
27+
pub fn otel_to_sentry_log(otel_log: OtelLog, received_at: DateTime<Utc>) -> Result<OurLog, Error> {
2828
let OtelLog {
2929
severity_number,
3030
severity_text,
@@ -46,9 +46,10 @@ pub fn otel_to_sentry_log(otel_log: OtelLog) -> Result<OurLog, Error> {
4646
})
4747
.unwrap_or_else(String::new);
4848

49-
// We ignore the passed observed time since Relay always acts as the collector in Sentry.
50-
// We may change this in the future with forwarding Relays.
51-
let observed_time_unix_nano = UnixTimestamp::now().as_nanos();
49+
let received_at_nanos = received_at
50+
.timestamp_nanos_opt()
51+
.unwrap_or_else(|| UnixTimestamp::now().as_nanos() as i64);
52+
5253
let mut attribute_data = Object::new();
5354

5455
attribute_data.insert(
@@ -83,7 +84,7 @@ pub fn otel_to_sentry_log(otel_log: OtelLog) -> Result<OurLog, Error> {
8384
"sentry.observed_timestamp_nanos".to_owned(),
8485
Annotated::new(Attribute::new(
8586
AttributeType::String,
86-
Value::String(observed_time_unix_nano.to_string()),
87+
Value::String(received_at_nanos.to_string()),
8788
)),
8889
);
8990
attribute_data.insert(
@@ -148,7 +149,7 @@ pub fn otel_to_sentry_log(otel_log: OtelLog) -> Result<OurLog, Error> {
148149
}
149150

150151
/// This fills attributes with OTel specific fields to be compatible with the otel schema.
151-
pub fn ourlog_merge_otel(ourlog: &mut Annotated<OurLog>) {
152+
pub fn ourlog_merge_otel(ourlog: &mut Annotated<OurLog>, received_at: DateTime<Utc>) {
152153
let Some(ourlog_value) = ourlog.value_mut() else {
153154
return;
154155
};
@@ -163,9 +164,9 @@ pub fn ourlog_merge_otel(ourlog: &mut Annotated<OurLog>) {
163164
})
164165
.unwrap_or_default();
165166

166-
// This is separate from the sdk provided time since Relay always acts as the collector in Sentry.
167-
// We may change this in the future with forwarding Relays.
168-
let observed_time_unix_nano = UnixTimestamp::now().as_nanos();
167+
let received_at_nanos = received_at
168+
.timestamp_nanos_opt()
169+
.unwrap_or_else(|| UnixTimestamp::now().as_nanos() as i64);
169170

170171
attributes.insert(
171172
"sentry.severity_text".to_owned(),
@@ -207,7 +208,7 @@ pub fn ourlog_merge_otel(ourlog: &mut Annotated<OurLog>) {
207208
"sentry.observed_timestamp_nanos".to_owned(),
208209
Annotated::new(Attribute::new(
209210
AttributeType::String,
210-
Value::String(observed_time_unix_nano.to_string()),
211+
Value::String(received_at_nanos.to_string()),
211212
)),
212213
);
213214
attributes.insert(
@@ -324,7 +325,9 @@ mod tests {
324325
}"#;
325326

326327
let otel_log: OtelLog = serde_json::from_str(json).unwrap();
327-
let our_log: OurLog = otel_to_sentry_log(otel_log).unwrap();
328+
let our_log: OurLog =
329+
otel_to_sentry_log(otel_log, DateTime::from_timestamp_nanos(946684800000000000))
330+
.unwrap();
328331
let annotated_log: Annotated<OurLog> = Annotated::new(our_log);
329332
assert_eq!(
330333
get_path!(annotated_log.body),
@@ -344,7 +347,8 @@ mod tests {
344347
}"#;
345348

346349
let otel_log: OtelLog = serde_json::from_str(json).unwrap();
347-
let our_log = otel_to_sentry_log(otel_log);
350+
let our_log =
351+
otel_to_sentry_log(otel_log, DateTime::from_timestamp_nanos(946684800000000000));
348352

349353
assert!(our_log.is_err());
350354
}
@@ -383,7 +387,9 @@ mod tests {
383387
]
384388
}"#;
385389
let otel_log: OtelLog = serde_json::from_str(json).unwrap();
386-
let our_log = otel_to_sentry_log(otel_log).unwrap();
390+
let our_log =
391+
otel_to_sentry_log(otel_log, DateTime::from_timestamp_nanos(946684800000000000))
392+
.unwrap();
387393
let annotated_log: Annotated<OurLog> = Annotated::new(our_log);
388394

389395
assert_eq!(
@@ -416,20 +422,17 @@ mod tests {
416422
"attributes": []
417423
}"#;
418424

419-
let before_test = UnixTimestamp::now().as_nanos();
420425
let otel_log: OtelLog = serde_json::from_str(json_without_observed_time).unwrap();
421-
let our_log: OurLog = otel_to_sentry_log(otel_log).unwrap();
422-
let after_test = UnixTimestamp::now().as_nanos();
426+
let our_log =
427+
otel_to_sentry_log(otel_log, DateTime::from_timestamp_nanos(946684800000000000))
428+
.unwrap();
423429

424-
// Get the observed timestamp from attributes
425430
let observed_timestamp = our_log
426431
.attribute("sentry.observed_timestamp_nanos")
427432
.and_then(|value| value.as_str().and_then(|s| s.parse::<u64>().ok()))
428433
.unwrap_or(0);
429434

430-
assert!(observed_timestamp > 0);
431-
assert!(observed_timestamp >= before_test);
432-
assert!(observed_timestamp <= after_test);
435+
assert_eq!(observed_timestamp, 946684800000000000);
433436
}
434437

435438
#[test]
@@ -447,20 +450,16 @@ mod tests {
447450
"attributes": []
448451
}"#;
449452

450-
let before_test = UnixTimestamp::now().as_nanos();
451453
let otel_log: OtelLog = serde_json::from_str(json_with_observed_time).unwrap();
452-
let our_log: OurLog = otel_to_sentry_log(otel_log).unwrap();
453-
let after_test = UnixTimestamp::now().as_nanos();
454+
let our_log: OurLog =
455+
otel_to_sentry_log(otel_log, DateTime::from_timestamp_nanos(946684800000000000))
456+
.unwrap();
454457

455-
// Get the observed timestamp from attributes
456458
let observed_timestamp = our_log
457459
.attribute("sentry.observed_timestamp_nanos")
458460
.and_then(|value| value.as_str().and_then(|s| s.parse::<u64>().ok()))
459461
.unwrap_or(0);
460462

461-
assert!(observed_timestamp > 0);
462-
assert!(observed_timestamp >= before_test);
463-
assert!(observed_timestamp <= after_test);
464463
assert_ne!(observed_timestamp, 1544712660300000000);
465464
}
466465

@@ -480,34 +479,11 @@ mod tests {
480479
}
481480
}"#;
482481

483-
let before_test = UnixTimestamp::now().as_nanos();
484482
let mut merged_log = Annotated::<OurLog>::from_json(json).unwrap();
485-
ourlog_merge_otel(&mut merged_log);
486-
let after_test = UnixTimestamp::now().as_nanos();
487-
488-
// Test the observed timestamp separately
489-
let observed_timestamp = merged_log
490-
.value()
491-
.and_then(|log| log.attribute("sentry.observed_timestamp_nanos"))
492-
.and_then(|attr| attr.as_str().and_then(|s| s.parse::<u64>().ok()))
493-
.unwrap_or(0);
494-
495-
assert!(observed_timestamp > 0);
496-
assert!(observed_timestamp >= before_test);
497-
assert!(observed_timestamp <= after_test);
498-
499-
// Set observed timestamp to a fixed value for snapshot testing
500-
if let Some(log) = merged_log.value_mut() {
501-
if let Some(attributes) = log.attributes.value_mut() {
502-
attributes.insert(
503-
"sentry.observed_timestamp_nanos".to_owned(),
504-
Annotated::new(Attribute::new(
505-
AttributeType::String,
506-
Value::String("946684800000000000".to_string()),
507-
)),
508-
);
509-
}
510-
}
483+
ourlog_merge_otel(
484+
&mut merged_log,
485+
DateTime::from_timestamp_nanos(946684800000000000),
486+
);
511487

512488
insta::assert_debug_snapshot!(merged_log, @r###"
513489
OurLog {
@@ -605,7 +581,10 @@ mod tests {
605581
}"#;
606582

607583
let mut data = Annotated::<OurLog>::from_json(json).unwrap();
608-
ourlog_merge_otel(&mut data);
584+
ourlog_merge_otel(
585+
&mut data,
586+
DateTime::from_timestamp_nanos(946684800000000000),
587+
);
609588
assert_eq!(
610589
data.value()
611590
.unwrap()
@@ -639,35 +618,12 @@ mod tests {
639618
..Default::default()
640619
});
641620

642-
let before_test = UnixTimestamp::now().as_nanos();
643-
ourlog_merge_otel(&mut ourlog);
644-
let after_test = UnixTimestamp::now().as_nanos();
645-
646-
// Test the observed timestamp separately
647-
let observed_timestamp = ourlog
648-
.value()
649-
.and_then(|log| log.attribute("sentry.observed_timestamp_nanos"))
650-
.and_then(|attr| attr.as_str().and_then(|s| s.parse::<u64>().ok()))
651-
.unwrap_or(0);
652-
653-
assert!(observed_timestamp > 0);
654-
assert!(observed_timestamp >= before_test);
655-
assert!(observed_timestamp <= after_test);
656-
657-
// Set observed timestamp to a fixed value for snapshot testing
658-
if let Some(log) = ourlog.value_mut() {
659-
if let Some(attributes) = log.attributes.value_mut() {
660-
attributes.insert(
661-
"sentry.observed_timestamp_nanos".to_owned(),
662-
Annotated::new(Attribute::new(
663-
AttributeType::String,
664-
Value::String("1638144000000000000".to_string()),
665-
)),
666-
);
667-
}
668-
}
621+
ourlog_merge_otel(
622+
&mut ourlog,
623+
DateTime::from_timestamp_nanos(946684800000000000),
624+
);
669625

670-
insta::assert_debug_snapshot!(ourlog, @r#"
626+
insta::assert_debug_snapshot!(ourlog, @r###"
671627
OurLog {
672628
timestamp: Timestamp(
673629
2021-11-29T00:00:00Z,
@@ -693,7 +649,7 @@ mod tests {
693649
},
694650
"sentry.observed_timestamp_nanos": Attribute {
695651
value: String(
696-
"1638144000000000000",
652+
"946684800000000000",
697653
),
698654
type: String,
699655
other: {},
@@ -736,9 +692,9 @@ mod tests {
736692
},
737693
other: {},
738694
}
739-
"#);
695+
"###);
740696

741-
insta::assert_json_snapshot!(SerializableAnnotated(&ourlog), @r#"
697+
insta::assert_json_snapshot!(SerializableAnnotated(&ourlog), @r###"
742698
{
743699
"timestamp": 1638144000.0,
744700
"body": "somebody",
@@ -753,7 +709,7 @@ mod tests {
753709
},
754710
"sentry.observed_timestamp_nanos": {
755711
"type": "string",
756-
"value": "1638144000000000000"
712+
"value": "946684800000000000"
757713
},
758714
"sentry.severity_number": {
759715
"type": "integer",
@@ -777,6 +733,6 @@ mod tests {
777733
}
778734
}
779735
}
780-
"#);
736+
"###);
781737
}
782738
}

‎relay-server/src/services/processor/ourlog/processing.rs‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -41,11 +41,12 @@ pub fn process(
4141
}
4242

4343
let normalize_config = NormalizeOurLogConfig::new(managed_envelope);
44+
let received_at = managed_envelope.received_at();
4445

4546
managed_envelope.retain_items(|item| {
4647
let mut logs = match item.ty() {
4748
ItemType::OtelLog => match serde_json::from_slice::<OtelLog>(&item.payload()) {
48-
Ok(otel_log) => match relay_ourlogs::otel_to_sentry_log(otel_log) {
49+
Ok(otel_log) => match relay_ourlogs::otel_to_sentry_log(otel_log, received_at) {
4950
Ok(log) => ContainerItems::from_elem(Annotated::new(log), 1),
5051
Err(err) => {
5152
relay_log::debug!("failed to convert OTel Log to Sentry Log: {:?}", err);
@@ -62,7 +63,7 @@ pub fn process(
6263
Ok(logs) => {
6364
let mut logs = logs.into_items();
6465
for log in logs.iter_mut() {
65-
relay_ourlogs::ourlog_merge_otel(log);
66+
relay_ourlogs::ourlog_merge_otel(log, received_at);
6667
}
6768
logs
6869
}

0 commit comments

Comments
 (0)