From f4c698ba27d2069f7aa952111cd4e3664844bccb Mon Sep 17 00:00:00 2001 From: "Joseph T. Lyons" Date: Thu, 11 Jan 2024 11:24:55 -0500 Subject: [PATCH 1/2] Fix bug with improperly reported environment When logging the edit environment, we were logging the newest environment being sent into the EventCoalescer on the latest activity log, when we should've been logging the environment that was associated with the ended period within the EventCoalescer. --- crates/client/src/telemetry.rs | 4 +- .../client/src/telemetry/event_coalescer.rs | 83 +++++++++++-------- 2 files changed, 52 insertions(+), 35 deletions(-) diff --git a/crates/client/src/telemetry.rs b/crates/client/src/telemetry.rs index 32ebaad3bdbadccd51a2c0520307898cd729cadd..7ce4b6e4f2ab10f9deed046917bd28ddbbd2d1e1 100644 --- a/crates/client/src/telemetry.rs +++ b/crates/client/src/telemetry.rs @@ -404,10 +404,10 @@ impl Telemetry { pub fn log_edit_event(self: &Arc, environment: &'static str) { let mut state = self.state.lock(); - let coalesced_duration = state.event_coalescer.log_event(environment); + let period_data = state.event_coalescer.log_event(environment); drop(state); - if let Some((start, end)) = coalesced_duration { + if let (Some((start, end)), Some(environment)) = period_data { let event = Event::Edit { duration: end.timestamp_millis() - start.timestamp_millis(), environment, diff --git a/crates/client/src/telemetry/event_coalescer.rs b/crates/client/src/telemetry/event_coalescer.rs index 96c61486b866c4521fe27eb8d9f3531cd5117661..4e6ddcbe7b2372e368e499dfb1a019c456907fa5 100644 --- a/crates/client/src/telemetry/event_coalescer.rs +++ b/crates/client/src/telemetry/event_coalescer.rs @@ -22,7 +22,7 @@ impl EventCoalescer { pub fn log_event( &mut self, environment: &'static str, - ) -> Option<(DateTime, DateTime)> { + ) -> (Option<(DateTime, DateTime)>, Option<&'static str>) { self.log_event_with_time(Utc::now(), environment) } @@ -34,13 +34,13 @@ impl EventCoalescer { &mut self, log_time: DateTime, environment: &'static str, - ) -> Option<(DateTime, DateTime)> { + ) -> (Option<(DateTime, DateTime)>, Option<&'static str>) { 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; + return (None, self.environment); }; let period_end = self @@ -51,18 +51,24 @@ impl EventCoalescer { let should_coaelesce = !within_timeout || !environment_is_same; if should_coaelesce { + let previous_environment = self.environment; + 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 }, - )); + + return ( + Some(( + period_start, + if within_timeout { log_time } else { period_end }, + )), + previous_environment, + ); } self.period_end = Some(log_time); - None + (None, self.environment) } } @@ -82,9 +88,9 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); assert_eq!(event_coalescer.period_start, Some(period_start)); assert_eq!(event_coalescer.period_end, None); assert_eq!(event_coalescer.environment, Some(environment_1)); @@ -95,9 +101,9 @@ mod tests { // 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); + let period_data = event_coalescer.log_event_with_time(period_end, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); 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)); @@ -106,10 +112,12 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(new_period_start, environment_1); - assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!( + period_data, + (Some((period_start, period_end)), Some(environment_1)) + ); 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)); @@ -125,18 +133,18 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); 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); + let period_data = event_coalescer.log_event_with_time(period_end, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); 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)); @@ -144,9 +152,12 @@ mod tests { // 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); + let period_data = event_coalescer.log_event_with_time(period_end, environment_2); - assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!( + period_data, + (Some((period_start, period_end)), Some(environment_1)) + ); assert_eq!(event_coalescer.period_start, Some(period_end)); assert_eq!(event_coalescer.period_end, None); assert_eq!(event_coalescer.environment, Some(environment_2)); @@ -162,9 +173,9 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); assert_eq!(event_coalescer.period_start, Some(period_start)); assert_eq!(event_coalescer.period_end, None); assert_eq!(event_coalescer.environment, Some(environment_1)); @@ -172,9 +183,12 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_end, environment_2); - assert_eq!(coalesced_duration, Some((period_start, period_end))); + assert_eq!( + period_data, + (Some((period_start, period_end)), Some(environment_1)) + ); assert_eq!(event_coalescer.period_start, Some(period_end)); assert_eq!(event_coalescer.period_end, None); assert_eq!(event_coalescer.environment, Some(environment_2)); @@ -196,9 +210,9 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(coalesced_duration, None); + assert_eq!(period_data, (None, Some(environment_1))); assert_eq!(event_coalescer.period_start, Some(period_start)); assert_eq!(event_coalescer.period_end, None); assert_eq!(event_coalescer.environment, Some(environment_1)); @@ -206,14 +220,17 @@ mod tests { 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); + let period_data = event_coalescer.log_event_with_time(period_end, environment_2); assert_eq!( - coalesced_duration, - Some(( - period_start, - period_start + SIMULATED_DURATION_FOR_SINGLE_EVENT - )) + period_data, + ( + Some(( + period_start, + period_start + SIMULATED_DURATION_FOR_SINGLE_EVENT + )), + Some(environment_1) + ) ); assert_eq!(event_coalescer.period_start, Some(period_end)); assert_eq!(event_coalescer.period_end, None); From 06ce1af5306b5a1f35de80613ed458cc9655b247 Mon Sep 17 00:00:00 2001 From: "Joseph T. Lyons" Date: Thu, 11 Jan 2024 11:30:22 -0500 Subject: [PATCH 2/2] Only return environment when period ends --- crates/client/src/telemetry/event_coalescer.rs | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/crates/client/src/telemetry/event_coalescer.rs b/crates/client/src/telemetry/event_coalescer.rs index 4e6ddcbe7b2372e368e499dfb1a019c456907fa5..9b3bf04c409893613e3fc4a40da5a4a5711b1e3a 100644 --- a/crates/client/src/telemetry/event_coalescer.rs +++ b/crates/client/src/telemetry/event_coalescer.rs @@ -40,7 +40,7 @@ impl EventCoalescer { let Some(period_start) = self.period_start else { self.period_start = Some(log_time); self.environment = Some(environment); - return (None, self.environment); + return (None, None); }; let period_end = self @@ -68,7 +68,7 @@ impl EventCoalescer { self.period_end = Some(log_time); - (None, self.environment) + (None, None) } } @@ -90,7 +90,7 @@ mod tests { let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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)); @@ -103,7 +103,7 @@ mod tests { period_end += within_timeout_adjustment; let period_data = event_coalescer.log_event_with_time(period_end, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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)); @@ -135,7 +135,7 @@ mod tests { let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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)); @@ -144,7 +144,7 @@ mod tests { let period_end = period_start + within_timeout_adjustment; let period_data = event_coalescer.log_event_with_time(period_end, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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)); @@ -175,7 +175,7 @@ mod tests { let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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)); @@ -212,7 +212,7 @@ mod tests { let period_start = Utc.with_ymd_and_hms(1990, 4, 12, 0, 0, 0).unwrap(); let period_data = event_coalescer.log_event_with_time(period_start, environment_1); - assert_eq!(period_data, (None, Some(environment_1))); + assert_eq!(period_data, (None, 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));