Skip to content

Commit 3239396

Browse files
committed
Clamp event timestamps to i64::MAX
BigQuery's integer type is a signed 64-bit value, while we collect unsigned ones. Timestamps are in milliseconds, so 9223372036854775807 (i64::MAX) ms is about 4.5 billion years, or roughly 1/15 of the age of earth. I think we should be fine with that for a little while longer. So any such value _should_ not happen. But it does in 0.002% of pings and thus data ends up in `additional_properties` instead of where it belongs. By clamping we might reduce that %age further. An event with that timestamp is most likely still not useful, but maybe the others are? One more problem is: Should we report this as an issue? If so how? Right now we don't have the APIs to tie that back to a specific event other then the one we own. But then our error types don't express the right things.
1 parent ae23788 commit 3239396

File tree

4 files changed

+97
-0
lines changed

4 files changed

+97
-0
lines changed

CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,10 @@
22

33
[Full changelog](https://github.com/mozilla/glean/compare/v66.3.0...main)
44

5+
* General
6+
* Event timestamps are now always clamped to the range of a signed 64-bit integer.
7+
An overflow is recorded in the new metric `glean.error.event_timestamp_clamped` in case this happens ([#3308](https://github.com/mozilla/glean/pull/3308)).
8+
59
# v66.3.0 (2025-12-19)
610

711
[Full changelog](https://github.com/mozilla/glean/compare/v66.2.0...v66.3.0)

glean-core/metrics.yaml

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -649,6 +649,24 @@ glean.error:
649649
650650
expires: never
651651

652+
event_timestamp_clamped:
653+
type: counter
654+
description: |
655+
The number of times we had to clamp an event timestamp
656+
for exceeding the range of a signed 64-bit integer (9223372036854775807).
657+
send_in_pings:
658+
- health
659+
bugs:
660+
- https://bugzilla.mozilla.org/show_bug.cgi?id=1873482
661+
data_reviews:
662+
- https://bugzilla.mozilla.org/show_bug.cgi?id=1873482
663+
data_sensitivity:
664+
- technical
665+
notification_emails:
666+
667+
668+
expires: 2026-06-31
669+
652670
glean.upload:
653671
ping_upload_failure:
654672
type: labeled_counter

glean-core/src/event_database/mod.rs

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -560,6 +560,22 @@ impl EventDatabase {
560560
// Let's fix cur_ec up and hope this isn't a sign something big is broken.
561561
cur_ec = execution_counter;
562562
}
563+
564+
// event timestamp is a `u64`, but BigQuery uses `i64` (signed!) everywhere. Let's clamp the value to make
565+
// sure we stay within bounds.
566+
if event.event.timestamp > i64::MAX as u64 {
567+
glean
568+
.additional_metrics
569+
.event_timestamp_clamped
570+
.add_sync(glean, 1);
571+
log::warn!(
572+
"Calculated event timestamp was too high. Got: {}, max: {}",
573+
event.event.timestamp,
574+
i64::MAX,
575+
);
576+
event.event.timestamp = event.event.timestamp.clamp(0, i64::MAX as u64);
577+
}
578+
563579
if highest_ts > event.event.timestamp {
564580
// Even though we sorted everything, something in the
565581
// execution_counter or glean.startup.date math went awry.
@@ -1357,4 +1373,50 @@ mod test {
13571373
)
13581374
.is_err());
13591375
}
1376+
1377+
#[test]
1378+
fn normalize_store_clamps_timestamp() {
1379+
let (glean, _dir) = new_glean(None);
1380+
1381+
let store_name = "store-name";
1382+
let event = RecordedEvent {
1383+
category: "category".into(),
1384+
name: "name".into(),
1385+
..Default::default()
1386+
};
1387+
1388+
let timestamps = [
1389+
0,
1390+
(i64::MAX / 2) as u64,
1391+
i64::MAX as _,
1392+
(i64::MAX as u64) + 1,
1393+
];
1394+
let mut store = timestamps
1395+
.into_iter()
1396+
.map(|timestamp| StoredEvent {
1397+
event: RecordedEvent {
1398+
timestamp,
1399+
..event.clone()
1400+
},
1401+
execution_counter: None,
1402+
})
1403+
.collect();
1404+
1405+
let glean_start_time = glean.start_time();
1406+
glean
1407+
.event_storage()
1408+
.normalize_store(&glean, store_name, &mut store, glean_start_time);
1409+
assert_eq!(4, store.len());
1410+
1411+
assert_eq!(0, store[0].event.timestamp);
1412+
assert_eq!((i64::MAX / 2) as u64, store[1].event.timestamp);
1413+
assert_eq!((i64::MAX as u64), store[2].event.timestamp);
1414+
assert_eq!((i64::MAX as u64), store[3].event.timestamp);
1415+
1416+
let error_count = glean
1417+
.additional_metrics
1418+
.event_timestamp_clamped
1419+
.get_value(&glean, "health");
1420+
assert_eq!(Some(1), error_count);
1421+
}
13601422
}

glean-core/src/internal_metrics.rs

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,10 @@ pub struct AdditionalMetrics {
4040
/// An experimentation identifier derived and provided by the application
4141
/// for the purpose of experimentation enrollment.
4242
pub experimentation_id: StringMetric,
43+
44+
/// The number of times we had to clamp an event timestamp
45+
/// for exceeding the range of a signed 64-bit integer (9223372036854775807).
46+
pub event_timestamp_clamped: CounterMetric,
4347
}
4448

4549
impl CoreMetrics {
@@ -198,6 +202,15 @@ impl AdditionalMetrics {
198202
disabled: false,
199203
dynamic_label: None,
200204
}),
205+
206+
event_timestamp_clamped: CounterMetric::new(CommonMetricData {
207+
name: "event_timestamp_clamped".into(),
208+
category: "glean.error".into(),
209+
send_in_pings: vec!["health".into()],
210+
lifetime: Lifetime::Ping,
211+
disabled: false,
212+
dynamic_label: None,
213+
}),
201214
}
202215
}
203216
}

0 commit comments

Comments
 (0)