Use Instant not chrono for telemetry (#20756)

We occasionally see dates in the future appearing in our telemetry. One
hypothesis is that this is caused by a clock change while Zed is running
causing date math based on chrono to be incorrect.

Instant *should* be a more stable source of relative timestamps.

Release Notes:

- N/A
This commit is contained in:
Conrad Irwin 2024-11-19 08:23:12 -07:00 committed by GitHub
parent 9454f0f1c7
commit 6a2c712990
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
12 changed files with 54 additions and 74 deletions

1
Cargo.lock generated
View file

@ -2473,7 +2473,6 @@ dependencies = [
name = "clock"
version = "0.1.0"
dependencies = [
"chrono",
"parking_lot",
"serde",
"smallvec",

View file

@ -343,7 +343,7 @@ fn init_test(cx: &mut AppContext) -> Model<ChannelStore> {
release_channel::init(SemanticVersion::default(), cx);
client::init_settings(cx);
let clock = Arc::new(FakeSystemClock::default());
let clock = Arc::new(FakeSystemClock::new());
let http = FakeHttpClient::with_404_response();
let client = Client::new(clock, http.clone(), cx);
let user_store = cx.new_model(|cx| UserStore::new(client.clone(), cx));

View file

@ -1780,7 +1780,7 @@ mod tests {
let user_id = 5;
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)
@ -1821,7 +1821,7 @@ mod tests {
let user_id = 5;
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)
@ -1900,7 +1900,7 @@ mod tests {
let dropped_auth_count = Arc::new(Mutex::new(0));
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)
@ -1943,7 +1943,7 @@ mod tests {
let user_id = 5;
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)
@ -2003,7 +2003,7 @@ mod tests {
let user_id = 5;
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)
@ -2038,7 +2038,7 @@ mod tests {
let user_id = 5;
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)

View file

@ -2,7 +2,6 @@ mod event_coalescer;
use crate::{ChannelId, TelemetrySettings};
use anyhow::Result;
use chrono::{DateTime, Utc};
use clock::SystemClock;
use collections::{HashMap, HashSet};
use futures::Future;
@ -15,6 +14,7 @@ use settings::{Settings, SettingsStore};
use sha2::{Digest, Sha256};
use std::fs::File;
use std::io::Write;
use std::time::Instant;
use std::{env, mem, path::PathBuf, sync::Arc, time::Duration};
use sysinfo::{CpuRefreshKind, Pid, ProcessRefreshKind, RefreshKind, System};
use telemetry_events::{
@ -46,7 +46,7 @@ struct TelemetryState {
flush_events_task: Option<Task<()>>,
log_file: Option<File>,
is_staff: Option<bool>,
first_event_date_time: Option<DateTime<Utc>>,
first_event_date_time: Option<Instant>,
event_coalescer: EventCoalescer,
max_queue_size: usize,
worktree_id_map: WorktreeIdMap,
@ -469,7 +469,10 @@ impl Telemetry {
if let Some((start, end, environment)) = period_data {
let event = Event::Edit(EditEvent {
duration: end.timestamp_millis() - start.timestamp_millis(),
duration: end
.saturating_duration_since(start)
.min(Duration::from_secs(60 * 60 * 24))
.as_millis() as i64,
environment: environment.to_string(),
is_via_ssh,
});
@ -567,9 +570,10 @@ impl Telemetry {
let date_time = self.clock.utc_now();
let milliseconds_since_first_event = match state.first_event_date_time {
Some(first_event_date_time) => {
date_time.timestamp_millis() - first_event_date_time.timestamp_millis()
}
Some(first_event_date_time) => date_time
.saturating_duration_since(first_event_date_time)
.min(Duration::from_secs(60 * 60 * 24))
.as_millis() as i64,
None => {
state.first_event_date_time = Some(date_time);
0
@ -702,7 +706,6 @@ pub fn calculate_json_checksum(json: &impl AsRef<[u8]>) -> Option<String> {
#[cfg(test)]
mod tests {
use super::*;
use chrono::TimeZone;
use clock::FakeSystemClock;
use gpui::TestAppContext;
use http_client::FakeHttpClient;
@ -710,9 +713,7 @@ mod tests {
#[gpui::test]
fn test_telemetry_flush_on_max_queue_size(cx: &mut TestAppContext) {
init_test(cx);
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 12, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let http = FakeHttpClient::with_200_response();
let system_id = Some("system_id".to_string());
let installation_id = Some("installation_id".to_string());
@ -743,7 +744,7 @@ mod tests {
Some(first_date_time)
);
clock.advance(chrono::Duration::milliseconds(100));
clock.advance(Duration::from_millis(100));
let event = telemetry.report_app_event(operation.clone());
assert_eq!(
@ -759,7 +760,7 @@ mod tests {
Some(first_date_time)
);
clock.advance(chrono::Duration::milliseconds(100));
clock.advance(Duration::from_millis(100));
let event = telemetry.report_app_event(operation.clone());
assert_eq!(
@ -775,7 +776,7 @@ mod tests {
Some(first_date_time)
);
clock.advance(chrono::Duration::milliseconds(100));
clock.advance(Duration::from_millis(100));
// Adding a 4th event should cause a flush
let event = telemetry.report_app_event(operation.clone());
@ -796,9 +797,7 @@ mod tests {
cx: &mut TestAppContext,
) {
init_test(cx);
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 12, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let http = FakeHttpClient::with_200_response();
let system_id = Some("system_id".to_string());
let installation_id = Some("installation_id".to_string());

View file

@ -1,7 +1,6 @@
use std::sync::Arc;
use std::time;
use std::{sync::Arc, time::Instant};
use chrono::{DateTime, Duration, Utc};
use clock::SystemClock;
const COALESCE_TIMEOUT: time::Duration = time::Duration::from_secs(20);
@ -10,8 +9,8 @@ const SIMULATED_DURATION_FOR_SINGLE_EVENT: time::Duration = time::Duration::from
#[derive(Debug, PartialEq)]
struct PeriodData {
environment: &'static str,
start: DateTime<Utc>,
end: Option<DateTime<Utc>>,
start: Instant,
end: Option<Instant>,
}
pub struct EventCoalescer {
@ -27,9 +26,8 @@ impl EventCoalescer {
pub fn log_event(
&mut self,
environment: &'static str,
) -> Option<(DateTime<Utc>, DateTime<Utc>, &'static str)> {
) -> Option<(Instant, Instant, &'static str)> {
let log_time = self.clock.utc_now();
let coalesce_timeout = Duration::from_std(COALESCE_TIMEOUT).unwrap();
let Some(state) = &mut self.state else {
self.state = Some(PeriodData {
@ -43,7 +41,7 @@ impl EventCoalescer {
let period_end = state
.end
.unwrap_or(state.start + SIMULATED_DURATION_FOR_SINGLE_EVENT);
let within_timeout = log_time - period_end < coalesce_timeout;
let within_timeout = log_time - period_end < COALESCE_TIMEOUT;
let environment_is_same = state.environment == environment;
let should_coaelesce = !within_timeout || !environment_is_same;
@ -70,16 +68,13 @@ impl EventCoalescer {
#[cfg(test)]
mod tests {
use chrono::TimeZone;
use clock::FakeSystemClock;
use super::*;
#[test]
fn test_same_context_exceeding_timeout() {
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let environment_1 = "environment_1";
let mut event_coalescer = EventCoalescer::new(clock.clone());
@ -98,7 +93,7 @@ mod tests {
})
);
let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap();
let within_timeout_adjustment = COALESCE_TIMEOUT / 2;
// Ensure that many calls within the timeout don't start a new period
for _ in 0..100 {
@ -118,7 +113,7 @@ mod tests {
}
let period_end = clock.utc_now();
let exceed_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT * 2).unwrap();
let exceed_timeout_adjustment = COALESCE_TIMEOUT * 2;
// Logging an event exceeding the timeout should start a new period
clock.advance(exceed_timeout_adjustment);
let new_period_start = clock.utc_now();
@ -137,9 +132,7 @@ mod tests {
#[test]
fn test_different_environment_under_timeout() {
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let environment_1 = "environment_1";
let mut event_coalescer = EventCoalescer::new(clock.clone());
@ -158,7 +151,7 @@ mod tests {
})
);
let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap();
let within_timeout_adjustment = COALESCE_TIMEOUT / 2;
clock.advance(within_timeout_adjustment);
let period_end = clock.utc_now();
let period_data = event_coalescer.log_event(environment_1);
@ -193,9 +186,7 @@ mod tests {
#[test]
fn test_switching_environment_while_within_timeout() {
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let environment_1 = "environment_1";
let mut event_coalescer = EventCoalescer::new(clock.clone());
@ -214,7 +205,7 @@ mod tests {
})
);
let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap();
let within_timeout_adjustment = COALESCE_TIMEOUT / 2;
clock.advance(within_timeout_adjustment);
let period_end = clock.utc_now();
let environment_2 = "environment_2";
@ -240,9 +231,7 @@ mod tests {
#[test]
fn test_switching_environment_while_exceeding_timeout() {
let clock = Arc::new(FakeSystemClock::new(
Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(),
));
let clock = Arc::new(FakeSystemClock::new());
let environment_1 = "environment_1";
let mut event_coalescer = EventCoalescer::new(clock.clone());
@ -261,7 +250,7 @@ mod tests {
})
);
let exceed_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT * 2).unwrap();
let exceed_timeout_adjustment = COALESCE_TIMEOUT * 2;
clock.advance(exceed_timeout_adjustment);
let period_end = clock.utc_now();
let environment_2 = "environment_2";

View file

@ -16,7 +16,6 @@ doctest = false
test-support = ["dep:parking_lot"]
[dependencies]
chrono.workspace = true
parking_lot = { workspace = true, optional = true }
serde.workspace = true
smallvec.workspace = true

View file

@ -1,21 +1,21 @@
use chrono::{DateTime, Utc};
use std::time::Instant;
pub trait SystemClock: Send + Sync {
/// Returns the current date and time in UTC.
fn utc_now(&self) -> DateTime<Utc>;
fn utc_now(&self) -> Instant;
}
pub struct RealSystemClock;
impl SystemClock for RealSystemClock {
fn utc_now(&self) -> DateTime<Utc> {
Utc::now()
fn utc_now(&self) -> Instant {
Instant::now()
}
}
#[cfg(any(test, feature = "test-support"))]
pub struct FakeSystemClockState {
now: DateTime<Utc>,
now: Instant,
}
#[cfg(any(test, feature = "test-support"))]
@ -24,36 +24,30 @@ pub struct FakeSystemClock {
state: parking_lot::Mutex<FakeSystemClockState>,
}
#[cfg(any(test, feature = "test-support"))]
impl Default for FakeSystemClock {
fn default() -> Self {
Self::new(Utc::now())
}
}
#[cfg(any(test, feature = "test-support"))]
impl FakeSystemClock {
pub fn new(now: DateTime<Utc>) -> Self {
let state = FakeSystemClockState { now };
pub fn new() -> Self {
let state = FakeSystemClockState {
now: Instant::now(),
};
Self {
state: parking_lot::Mutex::new(state),
}
}
pub fn set_now(&self, now: DateTime<Utc>) {
pub fn set_now(&self, now: Instant) {
self.state.lock().now = now;
}
/// Advances the [`FakeSystemClock`] by the specified [`Duration`](chrono::Duration).
pub fn advance(&self, duration: chrono::Duration) {
pub fn advance(&self, duration: std::time::Duration) {
self.state.lock().now += duration;
}
}
#[cfg(any(test, feature = "test-support"))]
impl SystemClock for FakeSystemClock {
fn utc_now(&self) -> DateTime<Utc> {
fn utc_now(&self) -> Instant {
self.state.lock().now
}
}

View file

@ -168,7 +168,7 @@ impl TestServer {
client::init_settings(cx);
});
let clock = Arc::new(FakeSystemClock::default());
let clock = Arc::new(FakeSystemClock::new());
let http = FakeHttpClient::with_404_response();
let user_id = if let Ok(Some(user)) = self.app_state.db.get_user_by_github_login(name).await
{

View file

@ -1133,7 +1133,7 @@ impl Project {
let fs = Arc::new(RealFs::default());
let languages = LanguageRegistry::test(cx.background_executor().clone());
let clock = Arc::new(FakeSystemClock::default());
let clock = Arc::new(FakeSystemClock::new());
let http_client = http_client::FakeHttpClient::with_404_response();
let client = cx
.update(|cx| client::Client::new(clock, http_client.clone(), cx))
@ -1179,7 +1179,7 @@ impl Project {
use gpui::Context;
let languages = LanguageRegistry::test(cx.executor());
let clock = Arc::new(FakeSystemClock::default());
let clock = Arc::new(FakeSystemClock::new());
let http_client = http_client::FakeHttpClient::with_404_response();
let client = cx.update(|cx| client::Client::new(clock, http_client.clone(), cx));
let user_store = cx.new_model(|cx| UserStore::new(client.clone(), cx));

View file

@ -1277,7 +1277,7 @@ fn build_project(ssh: Model<SshRemoteClient>, cx: &mut TestAppContext) -> Model<
let client = cx.update(|cx| {
Client::new(
Arc::new(FakeSystemClock::default()),
Arc::new(FakeSystemClock::new()),
FakeHttpClient::with_404_response(),
cx,
)

View file

@ -25,7 +25,7 @@ fn main() {
store.update_user_settings::<AllLanguageSettings>(cx, |_| {});
});
let clock = Arc::new(FakeSystemClock::default());
let clock = Arc::new(FakeSystemClock::new());
let http = Arc::new(HttpClientWithUrl::new(
Arc::new(

View file

@ -606,7 +606,7 @@ impl AppState {
let fs = fs::FakeFs::new(cx.background_executor().clone());
let languages = Arc::new(LanguageRegistry::test(cx.background_executor().clone()));
let clock = Arc::new(clock::FakeSystemClock::default());
let clock = Arc::new(clock::FakeSystemClock::new());
let http_client = http_client::FakeHttpClient::with_404_response();
let client = Client::new(clock, http_client.clone(), cx);
let session = cx.new_model(|cx| AppSession::new(Session::test(), cx));