WIP

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<dyn HttpClient>,
     executor: BackgroundExecutor,
@@ -34,6 +41,7 @@ struct TelemetryState {
     log_file: Option<NamedTempFile>,
     is_staff: Option<bool>,
     first_event_datetime: Option<DateTime<Utc>>,
+    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<dyn HttpClient>, cx: &mut AppContext) -> Arc<Self> {
@@ -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::<SettingsStore>({
@@ -392,6 +406,23 @@ impl Telemetry {
         }
     }
 
+    pub fn log_edit_event(self: &Arc<Self>, 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<Self>, 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();
                 }));
             }

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<DateTime<Utc>>,
+    period_end: Option<DateTime<Utc>>,
+}
+
+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<Utc>, DateTime<Utc>)> {
+        self.log_event_with_time(Utc::now(), environment)
+    }
+
+    fn log_event_with_time(
+        &mut self,
+        log_time: DateTime<Utc>,
+        environment: &'static str,
+    ) -> Option<(DateTime<Utc>, DateTime<Utc>)> {
+        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
+}