From 188fbc92d1c6dca0d89c7ef02bc0cd56e51aee28 Mon Sep 17 00:00:00 2001
From: Fengjiang Li <fengjial@google.com>
Date: Fri, 29 Sep 2023 11:24:04 -0700
Subject: [PATCH] [Launcher] Fix launcher startup logging

After reporting startup logs, we should tear down logger to prevent sending invalid logs

Bug: 302560751
Test: Verify rotating screen doesn't send startup logs to server
Change-Id: I8cf0a1a34aa9fffb67ddf83efe27908a28538551
---
 .../launcher3/logging/StartupLatencyLogger.kt | 27 +++++++++++++++++++
 .../logging/StartupLatencyLoggerTest.kt       | 22 +++++++++++++++
 2 files changed, 49 insertions(+)

diff --git a/src/com/android/launcher3/logging/StartupLatencyLogger.kt b/src/com/android/launcher3/logging/StartupLatencyLogger.kt
index 93e9de59b3..7d7564bce9 100644
--- a/src/com/android/launcher3/logging/StartupLatencyLogger.kt
+++ b/src/com/android/launcher3/logging/StartupLatencyLogger.kt
@@ -30,6 +30,11 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
     @VisibleForTesting(otherwise = VisibleForTesting.PROTECTED)
     var workspaceLoadStartTime: Long = UNSET_LONG
 
+    // StartupLatencyLogger should only send launcher startup logs once in each launcher activity
+    // lifecycle. After launcher activity startup is completed, the logger should be torn down and
+    // reject all logging calls. This flag should be checked at all APIs to prevent logging invalid
+    // startup metrics (such as loading workspace in screen rotation).
+    var isTornDown = false
     private var isInTest = false
 
     /** Subclass can override this method to handle collected latency metrics. */
@@ -45,6 +50,9 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
     @MainThread
     fun logWorkspaceLoadStartTime(startTimeMs: Long): StartupLatencyLogger {
         Preconditions.assertUIThread()
+        if (isTornDown) {
+            return this
+        }
         workspaceLoadStartTime = startTimeMs
         return this
     }
@@ -56,6 +64,9 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
     @MainThread
     fun logCardinality(cardinality: Int): StartupLatencyLogger {
         Preconditions.assertUIThread()
+        if (isTornDown) {
+            return this
+        }
         this.cardinality = cardinality
         return this
     }
@@ -67,6 +78,9 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
     fun logStart(event: LauncherLatencyEvent, startTimeMs: Long): StartupLatencyLogger {
         // In unit test no looper is attached to current thread
         Preconditions.assertUIThread()
+        if (isTornDown) {
+            return this
+        }
         if (validateLoggingEventAtStart(event)) {
             startTimeByEvent.put(event.id, startTimeMs)
         }
@@ -80,6 +94,9 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
     fun logEnd(event: LauncherLatencyEvent, endTimeMs: Long): StartupLatencyLogger {
         // In unit test no looper is attached to current thread
         Preconditions.assertUIThread()
+        if (isTornDown) {
+            return this
+        }
         maybeLogStartOfWorkspaceLoadTime(event)
         if (validateLoggingEventAtEnd(event)) {
             endTimeByEvent.put(event.id, endTimeMs)
@@ -96,6 +113,7 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
         endTimeByEvent.clear()
         cardinality = UNSET_INT
         workspaceLoadStartTime = UNSET_LONG
+        isTornDown = true
     }
 
     @MainThread
@@ -181,6 +199,15 @@ open class StartupLatencyLogger(val latencyType: LatencyType) {
                 "Cannot end ${event.name} event after ${LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.name}",
             )
             return false
+        } else if (
+            latencyType == LatencyType.COLD_DEVICE_REBOOTING &&
+                event == LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+        ) {
+            Log.e(
+                TAG,
+                "Cannot have ${LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC.name} in ${LatencyType.COLD_DEVICE_REBOOTING.name} startup type"
+            )
+            return false
         }
         return true
     }
diff --git a/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt b/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt
index fffa6d7b08..a29218cc35 100644
--- a/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt
+++ b/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt
@@ -357,6 +357,7 @@ class StartupLatencyLoggerTest {
         assertThat(underTest.startTimeByEvent.size()).isEqualTo(4)
         assertThat(underTest.endTimeByEvent.size()).isEqualTo(4)
         assertThat(underTest.cardinality).isEqualTo(235)
+        assertThat(underTest.isTornDown).isFalse()
 
         underTest.reset()
 
@@ -364,5 +365,26 @@ class StartupLatencyLoggerTest {
         assertThat(underTest.endTimeByEvent.isEmpty()).isTrue()
         assertThat(underTest.cardinality).isEqualTo(StartupLatencyLogger.UNSET_INT)
         assertThat(underTest.workspaceLoadStartTime).isEqualTo(StartupLatencyLogger.UNSET_LONG)
+        assertThat(underTest.isTornDown).isTrue()
+    }
+
+    @Test
+    @UiThreadTest
+    fun tornDown_rejectLogs() {
+        underTest.reset()
+
+        underTest
+            .logStart(
+                StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+                100
+            )
+            .logEnd(
+                StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+                200
+            )
+            .logCardinality(123)
+        assertThat(underTest.startTimeByEvent.isEmpty()).isTrue()
+        assertThat(underTest.endTimeByEvent.isEmpty()).isTrue()
+        assertThat(underTest.cardinality).isEqualTo(StartupLatencyLogger.UNSET_INT)
     }
 }