From d3d6b53a74befa93cfaa5b44f2e82dc7aea0d90c Mon Sep 17 00:00:00 2001 From: "Joseph T. Lyons" Date: Mon, 8 Jan 2024 16:32:59 -0500 Subject: [PATCH] WIP --- crates/client/src/telemetry.rs | 43 +++- .../client/src/telemetry/event_coalescer.rs | 224 ++++++++++++++++++ crates/editor/src/editor.rs | 4 + 3 files changed, 265 insertions(+), 6 deletions(-) create mode 100644 crates/client/src/telemetry/event_coalescer.rs diff --git a/crates/client/src/telemetry.rs b/crates/client/src/telemetry.rs index 26b5748187..6db434cffb 100644 --- a/crates/client/src/telemetry.rs +++ b/crates/client/src/telemetry.rs @@ -1,3 +1,9 @@ +// TODO - Test if locking slows Zed typing down +// TODO - Make sure to send last event on flush +// TODO - Move code to be used as arcs in editor and terminal + +mod event_coalescer; + use crate::{TelemetrySettings, ZED_SECRET_CLIENT_TOKEN, ZED_SERVER_URL}; use chrono::{DateTime, Utc}; use futures::Future; @@ -5,7 +11,6 @@ use gpui::{AppContext, AppMetadata, BackgroundExecutor, Task}; use lazy_static::lazy_static; use parking_lot::Mutex; use serde::Serialize; -use serde_json; use settings::{Settings, SettingsStore}; use std::{env, io::Write, mem, path::PathBuf, sync::Arc, time::Duration}; use sysinfo::{ @@ -15,6 +20,8 @@ use tempfile::NamedTempFile; use util::http::HttpClient; use util::{channel::ReleaseChannel, TryFutureExt}; +use self::event_coalescer::EventCoalescer; + pub struct Telemetry { http_client: Arc, executor: BackgroundExecutor, @@ -34,6 +41,7 @@ struct TelemetryState { log_file: Option, is_staff: Option, first_event_datetime: Option>, + edit_activity: EventCoalescer, } const EVENTS_URL_PATH: &'static str = "/api/events"; @@ -118,6 +126,11 @@ pub enum Event { value: String, milliseconds_since_first_event: i64, }, + Edit { + duration: i64, + environment: &'static str, + milliseconds_since_first_event: i64, + }, } #[cfg(debug_assertions)] @@ -127,10 +140,10 @@ const MAX_QUEUE_LEN: usize = 1; const MAX_QUEUE_LEN: usize = 50; #[cfg(debug_assertions)] -const DEBOUNCE_INTERVAL: Duration = Duration::from_secs(1); +const FLUSH_DEBOUNCE_INTERVAL: Duration = Duration::from_secs(1); #[cfg(not(debug_assertions))] -const DEBOUNCE_INTERVAL: Duration = Duration::from_secs(60 * 5); +const FLUSH_DEBOUNCE_INTERVAL: Duration = Duration::from_secs(60 * 5); impl Telemetry { pub fn new(client: Arc, cx: &mut AppContext) -> Arc { @@ -150,11 +163,12 @@ impl Telemetry { installation_id: None, metrics_id: None, session_id: None, - events_queue: Default::default(), - flush_events_task: Default::default(), + events_queue: Vec::new(), + flush_events_task: None, log_file: None, is_staff: None, first_event_datetime: None, + edit_activity: EventCoalescer::new(), })); cx.observe_global::({ @@ -392,6 +406,23 @@ impl Telemetry { } } + pub fn log_edit_event(self: &Arc, environment: &'static str) { + let mut state = self.state.lock(); + + let coalesced_duration = state.edit_activity.log_event(environment); + + if let Some((start, end)) = coalesced_duration { + let event = Event::Edit { + duration: end.timestamp_millis() - start.timestamp_millis(), + environment, + milliseconds_since_first_event: self.milliseconds_since_first_event(), + }; + + drop(state); + self.report_event(event); + } + } + fn report_event(self: &Arc, event: Event) { let mut state = self.state.lock(); @@ -410,7 +441,7 @@ impl Telemetry { let this = self.clone(); let executor = self.executor.clone(); state.flush_events_task = Some(self.executor.spawn(async move { - executor.timer(DEBOUNCE_INTERVAL).await; + executor.timer(FLUSH_DEBOUNCE_INTERVAL).await; this.flush_events(); })); } diff --git a/crates/client/src/telemetry/event_coalescer.rs b/crates/client/src/telemetry/event_coalescer.rs new file mode 100644 index 0000000000..6369ebccbc --- /dev/null +++ b/crates/client/src/telemetry/event_coalescer.rs @@ -0,0 +1,224 @@ +use chrono::{DateTime, Duration, Utc}; +use std::time; + +const COALESCE_TIMEOUT: time::Duration = time::Duration::from_secs(20); +const SIMULATED_DURATION_FOR_SINGLE_EVENT: time::Duration = time::Duration::from_millis(1); + +pub struct EventCoalescer { + environment: Option<&'static str>, + period_start: Option>, + period_end: Option>, +} + +impl EventCoalescer { + pub fn new() -> Self { + Self { + environment: None, + period_start: None, + period_end: None, + } + } + + pub fn log_event( + &mut self, + environment: &'static str, + ) -> Option<(DateTime, DateTime)> { + self.log_event_with_time(Utc::now(), environment) + } + + fn log_event_with_time( + &mut self, + log_time: DateTime, + environment: &'static str, + ) -> Option<(DateTime, DateTime)> { + let coalesce_timeout = Duration::from_std(COALESCE_TIMEOUT).unwrap(); + + let Some(period_start) = self.period_start else { + self.period_start = Some(log_time); + self.environment = Some(environment); + return None; + }; + + let period_end = self + .period_end + .unwrap_or(period_start + SIMULATED_DURATION_FOR_SINGLE_EVENT); + let within_timeout = log_time - period_end < coalesce_timeout; + let environment_is_same = self.environment == Some(environment); + let should_coaelesce = !within_timeout || !environment_is_same; + + if should_coaelesce { + self.period_start = Some(log_time); + self.period_end = None; + self.environment = Some(environment); + return Some(( + period_start, + if within_timeout { log_time } else { period_end }, + )); + } + + self.period_end = Some(log_time); + + None + } +} + +#[cfg(test)] +mod tests { + use chrono::TimeZone; + + use super::*; + + #[test] + fn test_same_context_exceeding_timeout() { + let environment_1 = "environment_1"; + let mut event_coalescer = EventCoalescer::new(); + + assert_eq!(event_coalescer.period_start, None); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, None); + + let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); + let coalesced_duration = event_coalescer.log_event_with_time(period_start, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_1)); + + let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap(); + let mut period_end = period_start; + + // Ensure that many calls within the timeout don't start a new period + for _ in 0..100 { + period_end += within_timeout_adjustment; + let coalesced_duration = event_coalescer.log_event_with_time(period_end, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, Some(period_end)); + assert_eq!(event_coalescer.environment, Some(environment_1)); + } + + let exceed_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT * 2).unwrap(); + // Logging an event exceeding the timeout should start a new period + let new_period_start = period_end + exceed_timeout_adjustment; + let coalesced_duration = + event_coalescer.log_event_with_time(new_period_start, environment_1); + + assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!(event_coalescer.period_start, Some(new_period_start)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_1)); + } + + #[test] + fn test_different_environment_under_timeout() { + let environment_1 = "environment_1"; + let mut event_coalescer = EventCoalescer::new(); + + assert_eq!(event_coalescer.period_start, None); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, None); + + let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); + let coalesced_duration = event_coalescer.log_event_with_time(period_start, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_1)); + + let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap(); + let period_end = period_start + within_timeout_adjustment; + let coalesced_duration = event_coalescer.log_event_with_time(period_end, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, Some(period_end)); + assert_eq!(event_coalescer.environment, Some(environment_1)); + + // Logging an event within the timeout but with a different environment should start a new period + let period_end = period_end + within_timeout_adjustment; + let environment_2 = "environment_2"; + let coalesced_duration = event_coalescer.log_event_with_time(period_end, environment_2); + + assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!(event_coalescer.period_start, Some(period_end)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_2)); + } + + #[test] + fn test_switching_environment_while_within_timeout() { + let environment_1 = "environment_1"; + let mut event_coalescer = EventCoalescer::new(); + + assert_eq!(event_coalescer.period_start, None); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, None); + + let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); + let coalesced_duration = event_coalescer.log_event_with_time(period_start, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_1)); + + let within_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT / 2).unwrap(); + let period_end = period_start + within_timeout_adjustment; + let environment_2 = "environment_2"; + let coalesced_duration = event_coalescer.log_event_with_time(period_end, environment_2); + + assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!(event_coalescer.period_start, Some(period_end)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_2)); + } + // 0 20 40 60 + // |-------------------|-------------------|-------------------|------------------- + // |--------|----------env change + // |------------------- + // |period_start |period_end + // |new_period_start + + #[test] + fn test_switching_environment_while_exceeding_timeout() { + let environment_1 = "environment_1"; + let mut event_coalescer = EventCoalescer::new(); + + assert_eq!(event_coalescer.period_start, None); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, None); + + let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); + let coalesced_duration = event_coalescer.log_event_with_time(period_start, environment_1); + + assert_eq!(coalesced_duration, None); + assert_eq!(event_coalescer.period_start, Some(period_start)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_1)); + + let exceed_timeout_adjustment = Duration::from_std(COALESCE_TIMEOUT * 2).unwrap(); + let period_end = period_start + exceed_timeout_adjustment; + let environment_2 = "environment_2"; + let coalesced_duration = event_coalescer.log_event_with_time(period_end, environment_2); + + assert_eq!( + coalesced_duration, + Some(( + period_start, + period_start + SIMULATED_DURATION_FOR_SINGLE_EVENT + )) + ); + assert_eq!(event_coalescer.period_start, Some(period_end)); + assert_eq!(event_coalescer.period_end, None); + assert_eq!(event_coalescer.environment, Some(environment_2)); + } + // 0 20 40 60 + // |-------------------|-------------------|-------------------|------------------- + // |--------|----------------------------------------env change + // |-------------------| + // |period_start |period_end + // |new_period_start +} diff --git a/crates/editor/src/editor.rs b/crates/editor/src/editor.rs index 231f76218a..0920de080e 100644 --- a/crates/editor/src/editor.rs +++ b/crates/editor/src/editor.rs @@ -8664,6 +8664,10 @@ impl Editor { } } } + + let Some(project) = &self.project else { return }; + let telemetry = project.read(cx).client().telemetry().clone(); + telemetry.log_edit_event("editor"); } multi_buffer::Event::ExcerptsAdded { buffer,