[board] Measure session, view and timed event durations on a monotonic clock

CHANGELOG.md

@@ -49,6 +49,7 @@
   * The token request is filed under the device ID that is current when it is queued.
 * Mitigated an issue where fatal crash reports were lost in explicit storage mode.
 * Mitigated an issue where a remote config download that finished after "halt()" stored the previous user's values.
+* Mitigated an issue where session, view and timed event durations changed when the device clock was adjusted. Event timestamps still follow the device clock.
 
 * Removed the following deprecated calls from "CountlyConfig":
   * "setMaxSegmentationValues(int)", use "sdkInternalLimits.setMaxSegmentationValues(int)" instead

sdk/src/androidTest/java/ly/count/android/sdk/CountlyTests.java

@@ -557,19 +557,19 @@ public void testOnTimer_activeSession_nonEmptyEventQueue() {
 
     @Test
     public void testRoundedSecondsSinceLastSessionDurationUpdate() {
-        long prevSessionDurationStartTime = System.currentTimeMillis() - 1000;
+        long prevSessionDurationStartTime = UtilsTime.monotonicTimeMs() - 1000;
         mCountly.setPrevSessionDurationStartTime(prevSessionDurationStartTime);
         assertEquals(1, mCountly.moduleSessions.roundedSecondsSinceLastSessionDurationUpdate());
 
-        prevSessionDurationStartTime = System.currentTimeMillis() - 2000;
+        prevSessionDurationStartTime = UtilsTime.monotonicTimeMs() - 2000;
         mCountly.setPrevSessionDurationStartTime(prevSessionDurationStartTime);
         assertEquals(2, mCountly.moduleSessions.roundedSecondsSinceLastSessionDurationUpdate());
 
-        prevSessionDurationStartTime = System.currentTimeMillis() - 1600;
+        prevSessionDurationStartTime = UtilsTime.monotonicTimeMs() - 1600;
         mCountly.setPrevSessionDurationStartTime(prevSessionDurationStartTime);
         assertEquals(2, mCountly.moduleSessions.roundedSecondsSinceLastSessionDurationUpdate());
 
-        prevSessionDurationStartTime = System.currentTimeMillis() - 1200;
+        prevSessionDurationStartTime = UtilsTime.monotonicTimeMs() - 1200;
         mCountly.setPrevSessionDurationStartTime(prevSessionDurationStartTime);
         assertEquals(1, mCountly.moduleSessions.roundedSecondsSinceLastSessionDurationUpdate());
     }

sdk/src/androidTest/java/ly/count/android/sdk/ModuleViewsTests.java

@@ -2233,7 +2233,7 @@ static void validateView(String viewName, Double viewDuration, int idx, int size
             viewSegmentation.put("cly_pvn", pvn);
         }
 
-        //The SDK reports view durations in WHOLE SECONDS (currentTimestampSeconds() - viewStartTimeSeconds),
+        //The SDK reports view durations in WHOLE SECONDS (monotonicTimeSeconds() - viewStartTimeSeconds),
         //and the tests that expect a non-zero duration produce it with Thread.sleep. A 1000 ms sleep plus any
         //scheduling delay therefore measures 1 or 2 depending on which side of a second boundary the clock
         //lands on, which is why CI failed with expected:<1.0> but was:<2.0> on a test that is not about

sdk/src/main/java/ly/count/android/sdk/Event.java

@@ -63,6 +63,7 @@ class Event {
     public String pvid;
     public String cvid;
     public String peid;
+    long monotonicStartMs; // start of a timed event on UtilsTime.monotonicTimeMs(), not serialized
 
     Event() {
     }

sdk/src/main/java/ly/count/android/sdk/ModuleEvents.java

@@ -360,7 +360,9 @@ boolean startEventInternal(final String key) {
         }
         L.d("[ModuleEvents] Starting event: [" + key + "]");
         UtilsTime.Instant instant = UtilsTime.getCurrentInstant();
-        timedEvents.put(key, new Event(key, instant.timestampMs, instant.hour, instant.dow));
+        Event timedEvent = new Event(key, instant.timestampMs, instant.hour, instant.dow);
+        timedEvent.monotonicStartMs = UtilsTime.monotonicTimeMs();
+        timedEvents.put(key, timedEvent);
         return true;
     }
 
@@ -385,8 +387,7 @@ boolean endEventInternal(@Nullable final String key, @Nullable final Map<String,
             }
             L.d("[ModuleEvents] Ending event: [" + key + "]");
 
-            long currentTimestamp = UtilsTime.currentTimestampMs();
-            double duration = (currentTimestamp - event.timestamp) / 1000.0;
+            double duration = (UtilsTime.monotonicTimeMs() - event.monotonicStartMs) / 1000.0;
             UtilsTime.Instant instant = new UtilsTime.Instant(event.timestamp, event.hour, event.dow);
 
             eventProvider.recordEventInternal(key, segmentation, count, sum, duration, instant, null);

sdk/src/main/java/ly/count/android/sdk/ModuleSessions.java

@@ -8,7 +8,7 @@
 public class ModuleSessions extends ModuleBase {
     boolean manualSessionControlEnabled = false;
     boolean manualSessionControlHybridModeEnabled = false;
-    long prevSessionDurationStartTime_ = System.currentTimeMillis();
+    long prevSessionDurationStartTime_ = UtilsTime.monotonicTimeMs();
     boolean sessionRunning = false;
     final Sessions sessionInterface;
 
@@ -67,7 +67,7 @@ void beginSessionInternal() {
         //prepare metrics
         String preparedMetrics = deviceInfo.getMetrics(_cly.context_, metricOverride, L);
         sessionRunning = true;
-        prevSessionDurationStartTime_ = System.currentTimeMillis();
+        prevSessionDurationStartTime_ = UtilsTime.monotonicTimeMs();
         if (userProfile != null) {
             userProfile.saveInternal();
         } else {
@@ -195,7 +195,7 @@ int roundedSecondsSinceLastSessionDurationUpdate() {
             L.e("[ModuleSessions] roundedSecondsSinceLastSessionDurationUpdate, called with prevSessionDurationStartTime_ being less than 1, returning 0, values was:[" + prevSessionDurationStartTime_ + "]");
             return 0;
         }
-        final long currentTimestampInMilliseconds = System.currentTimeMillis();
+        final long currentTimestampInMilliseconds = UtilsTime.monotonicTimeMs();
         final long unsentSessionLengthInMilliseconds = currentTimestampInMilliseconds - prevSessionDurationStartTime_;
         prevSessionDurationStartTime_ = currentTimestampInMilliseconds;
         int seconds = (int) Math.round(unsentSessionLengthInMilliseconds / 1_000.0d);

sdk/src/main/java/ly/count/android/sdk/ModuleViews.java

@@ -223,7 +223,7 @@ void autoCloseRequiredViews(boolean closeAllViews, @Nullable Map<String, Object>
         ViewData currentViewData = new ViewData();
         currentViewData.viewID = safeViewIDGenerator.GenerateValue();
         currentViewData.viewName = viewName;
-        currentViewData.viewStartTimeSeconds = UtilsTime.currentTimestampSeconds();
+        currentViewData.viewStartTimeSeconds = UtilsTime.monotonicTimeSeconds();
         currentViewData.isAutoStoppedView = viewShouldBeAutomaticallyStopped;
 
         viewDataMap.put(currentViewData.viewID, currentViewData);
@@ -294,7 +294,7 @@ void stopViewWithIDInternal(@Nullable String viewID, @Nullable Map<String, Objec
             return;
         }
 
-        L.d("[ModuleViews] View [" + vd.viewName + "], id:[" + vd.viewID + "] is getting closed, reporting duration: [" + (UtilsTime.currentTimestampSeconds() - vd.viewStartTimeSeconds) + "] s, current timestamp: [" + UtilsTime.currentTimestampSeconds() + "]");
+        L.d("[ModuleViews] View [" + vd.viewName + "], id:[" + vd.viewID + "] is getting closed, reporting duration: [" + (UtilsTime.monotonicTimeSeconds() - vd.viewStartTimeSeconds) + "] s, current timestamp: [" + UtilsTime.currentTimestampSeconds() + "]");
 
         if (!consentProvider.getConsent(Countly.CountlyFeatureNames.views)) {
             L.w("[ModuleViews] stopViewWithIDInternal, no consent given for views, ignoring call");
@@ -322,7 +322,7 @@ void recordViewEndEvent(ViewData vd, @Nullable Map<String, Object> customViewSeg
         } else if (vd.viewStartTimeSeconds == 0) {
             L.i("[ModuleViews] " + viewRecordingSource + ", view is either paused or didn't run, ignoring start timestamp");
         } else {
-            lastElapsedDurationSeconds = UtilsTime.currentTimestampSeconds() - vd.viewStartTimeSeconds;
+            lastElapsedDurationSeconds = UtilsTime.monotonicTimeSeconds() - vd.viewStartTimeSeconds;
         }
 
         //only record view if the view name is not null
@@ -415,7 +415,7 @@ void resumeViewWithIDInternal(String viewID) {
             return;
         }
 
-        vd.viewStartTimeSeconds = UtilsTime.currentTimestampSeconds();
+        vd.viewStartTimeSeconds = UtilsTime.monotonicTimeSeconds();
     }
 
     public void addSegmentationToViewWithIDInternal(@Nullable String viewID, @Nullable Map<String, Object> viewSegmentation) {

sdk/src/main/java/ly/count/android/sdk/UtilsTime.java

@@ -1,5 +1,6 @@
 package ly.count.android.sdk;
 
+import android.os.SystemClock;
 import java.util.ArrayList;
 import java.util.Calendar;
 import java.util.Collections;
@@ -62,6 +63,26 @@ public static synchronized long getNanoTime() {
         return System.nanoTime();
     }
 
+    /**
+     * Milliseconds since boot, including deep sleep, on a clock that a change of the device clock
+     * does not move. Only the difference between two values is meaningful, so durations are measured
+     * with it while timestamps stay on {@link #currentTimestampMs()}.
+     *
+     * @return monotonic time in milliseconds
+     */
+    static long monotonicTimeMs() {
+        return SystemClock.elapsedRealtime();
+    }
+
+    /**
+     * Whole seconds of {@link #monotonicTimeMs()}, for durations reported in seconds.
+     *
+     * @return monotonic time in seconds
+     */
+    static long monotonicTimeSeconds() {
+        return monotonicTimeMs() / 1000L;
+    }
+
     /**
      * Utility method to return a current timestamp in seconds.
      */