Skip to content

Commit b700f16

Browse files
authored
feat(ourlogs): Always set observed time for logs (#4559)
### Summary Observed time nanos should be set by the collector in OTel. In the case of Sentry the collector will always be Relay. We may want to allow passing observed time nanos in the future, but we can address that after we move to using EAP items consumers since they rely on 'received' instead of observed time.
1 parent fbc9e9a commit b700f16

File tree

5 files changed

+71
-1
lines changed

5 files changed

+71
-1
lines changed

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@
2727
- Update mapping of OTLP spans to Sentry spans in the experimental OTL traces endpoint. ([#4505](https://github.com/getsentry/relay/pull/4505))
2828
- Expose metrics for the `AsyncPool`. ([#4538](https://github.com/getsentry/relay/pull/4538))
2929
- Expose service utilization metrics through the internal relay metric endpoint. ([#4543](https://github.com/getsentry/relay/pull/4543))
30+
- Always set observed time for OTel logs in Relay. ([#4559](https://github.com/getsentry/relay/pull/4559))
3031

3132
## 25.2.0
3233

Cargo.lock

Lines changed: 1 addition & 0 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

relay-common/src/time.rs

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -109,6 +109,11 @@ impl UnixTimestamp {
109109
self.0
110110
}
111111

112+
/// Returns the number of nanoseconds since the UNIX epoch start. Precision limited to seconds.
113+
pub fn as_nanos(self) -> u64 {
114+
self.as_secs() * 1_000_000_000
115+
}
116+
112117
/// Returns the timestamp as chrono datetime.
113118
pub fn as_datetime(self) -> Option<DateTime<Utc>> {
114119
DateTime::from_timestamp(self.0 as i64, 0)

relay-ourlogs/Cargo.toml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@ opentelemetry-proto = { workspace = true, features = [
2323
] }
2424
relay-event-schema = { workspace = true }
2525
relay-protocol = { workspace = true }
26+
relay-common = { workspace = true }
2627
serde_json = { workspace = true }
2728

2829
[dev-dependencies]

relay-ourlogs/src/ourlog.rs

Lines changed: 63 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
use opentelemetry_proto::tonic::common::v1::any_value::Value as OtelValue;
22

33
use crate::OtelLog;
4+
use relay_common::time::UnixTimestamp;
45
use relay_event_schema::protocol::{AttributeValue, OurLog, SpanId, TraceId};
56
use relay_protocol::{Annotated, Object};
67

@@ -29,6 +30,10 @@ pub fn otel_to_sentry_log(otel_log: OtelLog) -> OurLog {
2930

3031
let mut attribute_data = Object::new();
3132

33+
// We ignore the passed observed time since Relay always acts as the collector in Sentry.
34+
// We may change this in the future with forwarding Relays.
35+
let observed_time_unix_nano = UnixTimestamp::now().as_nanos();
36+
3237
for attribute in attributes.into_iter() {
3338
if let Some(value) = attribute.value.and_then(|v| v.value) {
3439
let key = attribute.key;
@@ -58,7 +63,7 @@ pub fn otel_to_sentry_log(otel_log: OtelLog) -> OurLog {
5863

5964
OurLog {
6065
timestamp_nanos: Annotated::new(otel_log.time_unix_nano),
61-
observed_timestamp_nanos: Annotated::new(otel_log.observed_time_unix_nano),
66+
observed_timestamp_nanos: Annotated::new(observed_time_unix_nano),
6267
trace_id: TraceId(trace_id).into(),
6368
span_id: Annotated::new(SpanId(span_id)),
6469
trace_flags: Annotated::new(0),
@@ -201,4 +206,61 @@ mod tests {
201206
Some(&"SELECT \"table\".\"col\" FROM \"table\" WHERE \"table\".\"col\" = %s".into())
202207
);
203208
}
209+
210+
#[test]
211+
fn parse_log_without_observed_time() {
212+
let json_without_observed_time = r#"{
213+
"timeUnixNano": "1544712660300000000",
214+
"observedTimeUnixNano": "0",
215+
"severityNumber": 10,
216+
"severityText": "Information",
217+
"traceId": "5B8EFFF798038103D269B633813FC60C",
218+
"spanId": "EEE19B7EC3C1B174",
219+
"body": {
220+
"stringValue": "Example log record"
221+
},
222+
"attributes": []
223+
}"#;
224+
225+
let before_test = UnixTimestamp::now().as_nanos();
226+
let otel_log: OtelLog = serde_json::from_str(json_without_observed_time).unwrap();
227+
let our_log: OurLog = otel_to_sentry_log(otel_log);
228+
let after_test = UnixTimestamp::now().as_nanos();
229+
230+
let observed_time = our_log.observed_timestamp_nanos.value().unwrap();
231+
assert!(*observed_time > 0);
232+
assert!(*observed_time >= before_test);
233+
assert!(*observed_time <= after_test);
234+
}
235+
236+
#[test]
237+
fn parse_log_ignores_observed_time() {
238+
let json_with_observed_time = r#"{
239+
"timeUnixNano": "1544712660300000000",
240+
"observedTimeUnixNano": "1544712660300000000",
241+
"severityNumber": 10,
242+
"severityText": "Information",
243+
"traceId": "5B8EFFF798038103D269B633813FC60C",
244+
"spanId": "EEE19B7EC3C1B174",
245+
"body": {
246+
"stringValue": "Example log record"
247+
},
248+
"attributes": []
249+
}"#;
250+
251+
let before_test = UnixTimestamp::now().as_nanos();
252+
let otel_log: OtelLog = serde_json::from_str(json_with_observed_time).unwrap();
253+
let our_log: OurLog = otel_to_sentry_log(otel_log);
254+
let after_test = UnixTimestamp::now().as_nanos();
255+
256+
let observed_time = our_log.observed_timestamp_nanos.value().unwrap();
257+
assert!(*observed_time > 0);
258+
assert!(*observed_time >= before_test);
259+
assert!(*observed_time <= after_test);
260+
261+
assert_ne!(
262+
our_log.observed_timestamp_nanos,
263+
Annotated::new(1544712660300000000)
264+
);
265+
}
204266
}

0 commit comments

Comments
 (0)