From 6a2c7129908389c772f15a4890e83e2bea4a7e3c Mon Sep 17 00:00:00 2001 From: Conrad Irwin Date: Tue, 19 Nov 2024 08:23:12 -0700 Subject: [PATCH] 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 --- Cargo.lock | 1 - crates/channel/src/channel_store_tests.rs | 2 +- crates/client/src/client.rs | 12 +++--- crates/client/src/telemetry.rs | 31 +++++++-------- .../client/src/telemetry/event_coalescer.rs | 39 +++++++------------ crates/clock/Cargo.toml | 1 - crates/clock/src/system_clock.rs | 30 ++++++-------- crates/collab/src/tests/test_server.rs | 2 +- crates/project/src/project.rs | 4 +- .../remote_server/src/remote_editing_tests.rs | 2 +- crates/semantic_index/examples/index.rs | 2 +- crates/workspace/src/workspace.rs | 2 +- 12 files changed, 54 insertions(+), 74 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 7f5934fca8..38de2f5c00 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2473,7 +2473,6 @@ dependencies = [ name = "clock" version = "0.1.0" dependencies = [ - "chrono", "parking_lot", "serde", "smallvec", diff --git a/crates/channel/src/channel_store_tests.rs b/crates/channel/src/channel_store_tests.rs index 1cf9fa706d..11f618d196 100644 --- a/crates/channel/src/channel_store_tests.rs +++ b/crates/channel/src/channel_store_tests.rs @@ -343,7 +343,7 @@ fn init_test(cx: &mut AppContext) -> Model { 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)); diff --git a/crates/client/src/client.rs b/crates/client/src/client.rs index 1e73c7be66..041973e884 100644 --- a/crates/client/src/client.rs +++ b/crates/client/src/client.rs @@ -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, ) diff --git a/crates/client/src/telemetry.rs b/crates/client/src/telemetry.rs index 27a49a9816..b472cf768e 100644 --- a/crates/client/src/telemetry.rs +++ b/crates/client/src/telemetry.rs @@ -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>, log_file: Option, is_staff: Option, - first_event_date_time: Option>, + first_event_date_time: Option, 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 { #[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()); diff --git a/crates/client/src/telemetry/event_coalescer.rs b/crates/client/src/telemetry/event_coalescer.rs index 33bcf492f6..e58112ac08 100644 --- a/crates/client/src/telemetry/event_coalescer.rs +++ b/crates/client/src/telemetry/event_coalescer.rs @@ -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, - end: Option>, + start: Instant, + end: Option, } pub struct EventCoalescer { @@ -27,9 +26,8 @@ impl EventCoalescer { pub fn log_event( &mut self, environment: &'static str, - ) -> Option<(DateTime, DateTime, &'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"; diff --git a/crates/clock/Cargo.toml b/crates/clock/Cargo.toml index 699a50e70d..b6f28741c3 100644 --- a/crates/clock/Cargo.toml +++ b/crates/clock/Cargo.toml @@ -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 diff --git a/crates/clock/src/system_clock.rs b/crates/clock/src/system_clock.rs index a462ffc35b..b8e50d0b27 100644 --- a/crates/clock/src/system_clock.rs +++ b/crates/clock/src/system_clock.rs @@ -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; + fn utc_now(&self) -> Instant; } pub struct RealSystemClock; impl SystemClock for RealSystemClock { - fn utc_now(&self) -> DateTime { - Utc::now() + fn utc_now(&self) -> Instant { + Instant::now() } } #[cfg(any(test, feature = "test-support"))] pub struct FakeSystemClockState { - now: DateTime, + now: Instant, } #[cfg(any(test, feature = "test-support"))] @@ -24,36 +24,30 @@ pub struct FakeSystemClock { state: parking_lot::Mutex, } -#[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) -> 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) { + 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 { + fn utc_now(&self) -> Instant { self.state.lock().now } } diff --git a/crates/collab/src/tests/test_server.rs b/crates/collab/src/tests/test_server.rs index 17cd1b51c4..8a09f06092 100644 --- a/crates/collab/src/tests/test_server.rs +++ b/crates/collab/src/tests/test_server.rs @@ -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 { diff --git a/crates/project/src/project.rs b/crates/project/src/project.rs index 17f84a6f37..2b18659b7d 100644 --- a/crates/project/src/project.rs +++ b/crates/project/src/project.rs @@ -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)); diff --git a/crates/remote_server/src/remote_editing_tests.rs b/crates/remote_server/src/remote_editing_tests.rs index e3914c7ae1..3a9803287a 100644 --- a/crates/remote_server/src/remote_editing_tests.rs +++ b/crates/remote_server/src/remote_editing_tests.rs @@ -1277,7 +1277,7 @@ fn build_project(ssh: Model, cx: &mut TestAppContext) -> Model< let client = cx.update(|cx| { Client::new( - Arc::new(FakeSystemClock::default()), + Arc::new(FakeSystemClock::new()), FakeHttpClient::with_404_response(), cx, ) diff --git a/crates/semantic_index/examples/index.rs b/crates/semantic_index/examples/index.rs index 2efd94cb57..25e03f5b3a 100644 --- a/crates/semantic_index/examples/index.rs +++ b/crates/semantic_index/examples/index.rs @@ -25,7 +25,7 @@ fn main() { store.update_user_settings::(cx, |_| {}); }); - let clock = Arc::new(FakeSystemClock::default()); + let clock = Arc::new(FakeSystemClock::new()); let http = Arc::new(HttpClientWithUrl::new( Arc::new( diff --git a/crates/workspace/src/workspace.rs b/crates/workspace/src/workspace.rs index 833a8b15a0..32e441ee50 100644 --- a/crates/workspace/src/workspace.rs +++ b/crates/workspace/src/workspace.rs @@ -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));