Fixes #4466: CPU Usage performance metrics logging

domain/src/main/java/org/oppia/android/domain/oppialogger/analytics/CpuPerformanceLoggingTimePeriodMillis.kt

@@ -15,3 +15,11 @@ annotation class ForegroundCpuLoggingTimePeriodMillis
  */
 @Qualifier
 annotation class BackgroundCpuLoggingTimePeriodMillis
+
+/**
+ * Corresponds to an injectable application-level [Long] that corresponds to the number of
+ * milliseconds after which the initial iconification is set to background if it is uninitialized
+ * until that point.
+ */
+@Qualifier
+annotation class InitialIconificationCutOffTimePeriodMillis

domain/src/main/java/org/oppia/android/domain/oppialogger/analytics/CpuPerformanceSnapshotter.kt

@@ -8,10 +8,16 @@ import kotlinx.coroutines.channels.actor
 import kotlinx.coroutines.delay
 import kotlinx.coroutines.launch
 import org.oppia.android.app.model.ScreenName
+import org.oppia.android.app.model.ScreenName.BACKGROUND_SCREEN
+import org.oppia.android.app.model.ScreenName.FOREGROUND_SCREEN
+import org.oppia.android.app.model.ScreenName.SCREEN_NAME_UNSPECIFIED
 import org.oppia.android.util.logging.ConsoleLogger
 import org.oppia.android.util.logging.ExceptionLogger
 import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor
 import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor.AppIconification
+import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor.AppIconification.APP_IN_BACKGROUND
+import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor.AppIconification.APP_IN_FOREGROUND
+import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor.AppIconification.UNINITIALIZED
 import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAssessor.CpuSnapshot
 
 /**
@@ -24,12 +30,13 @@ class CpuPerformanceSnapshotter(
   private val initialIconification: AppIconification,
   private val consoleLogger: ConsoleLogger,
   private val exceptionLogger: ExceptionLogger,
+  private val performanceMetricsAssessor: PerformanceMetricsAssessor,
   private val foregroundCpuLoggingTimePeriodMillis: Long,
   private val backgroundCpuLoggingTimePeriodMillis: Long,
-  private val performanceMetricsAssessor: PerformanceMetricsAssessor
+  private val initialIconificationCutOffTimePeriodMillis: Long
 ) {
 
-  private val commandQueue by lazy { createCommandQueueActor() }
+  private val commandQueue = createCommandQueueActor()
 
   /** Updates the current [AppIconification] in accordance with the app's state changes. */
   fun updateAppIconification(newIconification: AppIconification) {
@@ -38,23 +45,24 @@ class CpuPerformanceSnapshotter(
 
   private fun createCommandQueueActor(): SendChannel<CommandMessage> {
     var currentIconification = initialIconification
-    var previousSnapshot =
-      performanceMetricsAssessor.computeCpuSnapshotAtCurrentTime()
+    var previousSnapshot = performanceMetricsAssessor.computeCpuSnapshotAtCurrentTime()
     var switchIconificationCount = 0
     val coroutineScope = CoroutineScope(backgroundCoroutineDispatcher)
     return coroutineScope.actor<CommandMessage>(capacity = Channel.UNLIMITED) {
       for (message in channel) {
         when (message) {
           is CommandMessage.SwitchIconification -> {
             ++switchIconificationCount
-            // Since there's a switch in the current iconification of the app, we'd cut short the
-            // existing delay and log the current CPU usage relative to the previously logged one
-            // without this explicit log command.
-            performanceMetricsAssessor.getRelativeCpuUsage(
-              previousSnapshot,
-              performanceMetricsAssessor.computeCpuSnapshotAtCurrentTime()
-            )?.let { relativeCpuUsage ->
-              sendLogSnapshotDiffCommand(relativeCpuUsage, currentIconification)
+            if (currentIconification != UNINITIALIZED) {
+              // Since there's a switch in the current iconification of the app, we'd cut short the
+              // existing delay and log the current CPU usage relative to the previously logged one
+              // without this explicit log command.
+              performanceMetricsAssessor.getRelativeCpuUsage(
+                previousSnapshot,
+                performanceMetricsAssessor.computeCpuSnapshotAtCurrentTime()
+              )?.let { relativeCpuUsage ->
+                sendLogSnapshotDiffCommand(relativeCpuUsage, currentIconification)
+              }
             }
             currentIconification = message.newIconification
             previousSnapshot = performanceMetricsAssessor.computeCpuSnapshotAtCurrentTime()
@@ -88,7 +96,10 @@ class CpuPerformanceSnapshotter(
       }
     }.also {
       CoroutineScope(backgroundCoroutineDispatcher).launch {
-        sendTakeSnapshotCommand(switchIconificationCount)
+        delay(initialIconificationCutOffTimePeriodMillis)
+        if (currentIconification == UNINITIALIZED) {
+          sendSwitchIconificationCommand(APP_IN_BACKGROUND)
+        }
       }
     }
   }
@@ -110,9 +121,7 @@ class CpuPerformanceSnapshotter(
   private suspend fun sendScheduleTakeSnapshotCommand(
     currentIconification: AppIconification,
     switchId: Int
-  ) {
-    commandQueue.send(CommandMessage.ScheduleTakeSnapshot(currentIconification, switchId))
-  }
+  ) { commandQueue.send(CommandMessage.ScheduleTakeSnapshot(currentIconification, switchId)) }
 
   private suspend fun sendTakeSnapshotCommand(switchId: Int) {
     commandQueue.send(CommandMessage.TakeSnapshot(switchId))
@@ -188,13 +197,15 @@ class CpuPerformanceSnapshotter(
 
   /** Returns an appropriate [ScreenName] on the basis of [AppIconification]. */
   private fun AppIconification.toScreenName(): ScreenName = when (this) {
-    AppIconification.APP_IN_BACKGROUND -> ScreenName.BACKGROUND_SCREEN
-    AppIconification.APP_IN_FOREGROUND -> ScreenName.FOREGROUND_SCREEN
+    APP_IN_BACKGROUND -> BACKGROUND_SCREEN
+    APP_IN_FOREGROUND -> FOREGROUND_SCREEN
+    UNINITIALIZED -> SCREEN_NAME_UNSPECIFIED
   }
 
   /** Returns an appropriate delay time period in millis on the basis of [AppIconification]. */
   private fun AppIconification.getDelay(): Long = when (this) {
-    AppIconification.APP_IN_BACKGROUND -> backgroundCpuLoggingTimePeriodMillis
-    AppIconification.APP_IN_FOREGROUND -> foregroundCpuLoggingTimePeriodMillis
+    APP_IN_BACKGROUND -> backgroundCpuLoggingTimePeriodMillis
+    APP_IN_FOREGROUND -> foregroundCpuLoggingTimePeriodMillis
+    UNINITIALIZED -> initialIconificationCutOffTimePeriodMillis
   }
 }

domain/src/main/java/org/oppia/android/domain/oppialogger/analytics/CpuPerformanceSnapshotterModule.kt

@@ -20,19 +20,21 @@ class CpuPerformanceSnapshotterModule {
     performanceMetricsLogger: PerformanceMetricsLogger,
     consoleLogger: ConsoleLogger,
     exceptionLogger: ExceptionLogger,
+    performanceMetricsAssessor: PerformanceMetricsAssessor,
+    @BackgroundDispatcher backgroundCoroutineDispatcher: CoroutineDispatcher,
     @ForegroundCpuLoggingTimePeriodMillis foregroundCpuLoggingTimePeriodMillis: Long,
     @BackgroundCpuLoggingTimePeriodMillis backgroundCpuLoggingTimePeriodMillis: Long,
-    @BackgroundDispatcher backgroundCoroutineDispatcher: CoroutineDispatcher,
-    performanceMetricsAssessor: PerformanceMetricsAssessor
+    @InitialIconificationCutOffTimePeriodMillis initialIconificationCutOffTimePeriodMillis: Long
   ): CpuPerformanceSnapshotter = CpuPerformanceSnapshotter(
     backgroundCoroutineDispatcher,
     performanceMetricsLogger,
-    PerformanceMetricsAssessor.AppIconification.APP_IN_BACKGROUND,
+    PerformanceMetricsAssessor.AppIconification.UNINITIALIZED,
     consoleLogger,
     exceptionLogger,
+    performanceMetricsAssessor,
     foregroundCpuLoggingTimePeriodMillis,
     backgroundCpuLoggingTimePeriodMillis,
-    performanceMetricsAssessor
+    initialIconificationCutOffTimePeriodMillis
   )
 
   @Provides
@@ -42,4 +44,8 @@ class CpuPerformanceSnapshotterModule {
   @Provides
   @BackgroundCpuLoggingTimePeriodMillis
   fun provideBackgroundCpuLoggingTimePeriodMillis(): Long = TimeUnit.MINUTES.toMillis(60)
+
+  @Provides
+  @InitialIconificationCutOffTimePeriodMillis
+  fun provideInitialIconificationCutOffTimePeriodMillis(): Long = TimeUnit.SECONDS.toMillis(60)
 }

domain/src/test/java/org/oppia/android/domain/oppialogger/analytics/CpuPerformanceSnapshotterTest.kt

@@ -41,6 +41,7 @@ import org.oppia.android.util.logging.performancemetrics.PerformanceMetricsAsses
 import org.oppia.android.util.networking.NetworkConnectionUtilDebugModule
 import org.robolectric.annotation.Config
 import org.robolectric.annotation.LooperMode
+import java.util.concurrent.TimeUnit
 import javax.inject.Inject
 import javax.inject.Singleton
 
@@ -68,6 +69,9 @@ class CpuPerformanceSnapshotterTest {
   @field:[JvmField Inject BackgroundCpuLoggingTimePeriodMillis]
   var backgroundCpuLoggingTimePeriodMillis: Long = Long.MIN_VALUE
 
+  @field:[JvmField Inject InitialIconificationCutOffTimePeriodMillis]
+  var initialIconificationCutOffTimePeriodMillis: Long = Long.MIN_VALUE
+
   @Before
   fun setUp() {
     TestPlatformParameterModule.forceEnablePerformanceMetricsCollection(true)
@@ -109,19 +113,21 @@ class CpuPerformanceSnapshotterTest {
     cpuPerformanceSnapshotter.updateAppIconification(APP_IN_BACKGROUND)
     testCoroutineDispatchers.runCurrent()
     testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
+    cpuPerformanceSnapshotter.updateAppIconification(APP_IN_FOREGROUND)
+    testCoroutineDispatchers.runCurrent()
 
     val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
     val latestEvents =
       fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
-    // Event that got logged after time advancement.
+    // Event that got logged on third update call.
     val latestEvent = latestEvents[count - 1]
-    // Event that got logged on second iconification update.
+    // Event that got logged after time advancement.
     val secondLatestEvent = latestEvents[count - 2]
-    // Event that got logged on first iconification update.
+    // Event that got logged on second update call.
     val thirdLatestEvent = latestEvents[count - 3]
 
     assertThat(latestEvent.currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
-    assertThat(secondLatestEvent.currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+    assertThat(secondLatestEvent.currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
     assertThat(thirdLatestEvent.currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
   }
 
@@ -130,6 +136,7 @@ class CpuPerformanceSnapshotterTest {
     fakePerformanceMetricAssessor.setRelativeCpuUsage(TEST_CPU_USAGE_ONE)
     cpuPerformanceSnapshotter.updateAppIconification(APP_IN_FOREGROUND)
     testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
     val firstEvent = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvent()
 
     fakePerformanceMetricAssessor.setRelativeCpuUsage(TEST_CPU_USAGE_TWO)
@@ -163,6 +170,7 @@ class CpuPerformanceSnapshotterTest {
     fakePerformanceMetricAssessor.setRelativeCpuUsage(TEST_CPU_USAGE_ONE)
     cpuPerformanceSnapshotter.updateAppIconification(APP_IN_BACKGROUND)
     testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
     val firstEvent = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvent()
 
     fakePerformanceMetricAssessor.setRelativeCpuUsage(TEST_CPU_USAGE_TWO)
@@ -215,6 +223,7 @@ class CpuPerformanceSnapshotterTest {
     fakePerformanceMetricAssessor.setRelativeCpuUsage(TEST_CPU_USAGE_ONE)
     cpuPerformanceSnapshotter.updateAppIconification(APP_IN_FOREGROUND)
     testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
 
     val latestEvent = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvent()
 
@@ -231,6 +240,127 @@ class CpuPerformanceSnapshotterTest {
     assertThat(fakePerformanceMetricsEventLogger.noPerformanceMetricsEventsPresent()).isTrue()
   }
 
+  @Test
+  fun testSnapshotter_onCreate_moveToForegroundBeforeCutOff_logsCpuUsageInForegroundAfterDelay() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(1000)
+    applicationLifecycleObserver.onAppInForeground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val event = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvent()
+
+    assertThat(count).isEqualTo(1)
+    assertThat(event).isNotNull()
+    assertThat(event.currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+  }
+
+  @Test
+  fun testSnapshotter_moveToFgBeforeCutOff_moveToBgBeforeDelayEnds_logsInFg_logsInBgAfterDelay() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(1000)
+    applicationLifecycleObserver.onAppInForeground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(TimeUnit.MINUTES.toMillis(2))
+    applicationLifecycleObserver.onAppInBackground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val events = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
+
+    assertThat(count).isEqualTo(2)
+    assertThat(events[0].currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+    assertThat(events[1].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+  }
+
+  @Test
+  fun testSnapshotter_moveToFgBeforeCutOff_moveToBgAfterFirstDelay_logsCpuWithCorrectIcon() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(1000)
+    applicationLifecycleObserver.onAppInForeground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
+    testCoroutineDispatchers.advanceTimeBy(TimeUnit.MINUTES.toMillis(1))
+    applicationLifecycleObserver.onAppInBackground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val events = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
+
+    assertThat(count).isEqualTo(3)
+    assertThat(events[0].currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+    assertThat(events[1].currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+    assertThat(events[2].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+  }
+
+  @Test
+  fun testSnapshotter_onCreate_setsIconificationToBgAfterCutOff_logsCpuInBgAfterCorrectDelay() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(initialIconificationCutOffTimePeriodMillis)
+    testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val events = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
+
+    assertThat(count).isEqualTo(1)
+    assertThat(events[0].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+  }
+
+  @Test
+  fun testSnapshotter_onCreate_setsIconToBgAfterCutOff_moveToFgAndLogsCpuInBg_logsCpuInFg() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(TimeUnit.MINUTES.toMillis(5))
+    applicationLifecycleObserver.onAppInForeground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val events = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
+
+    assertThat(count).isEqualTo(2)
+    assertThat(events[0].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+    assertThat(events[1].currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+  }
+
+  @Test
+  fun testSnapshotter_setsIconToBgAfterCutOff_logsCpuInBg_moveToFgAndLogsCpuInBg_logsCpuInFg() {
+    applicationLifecycleObserver.onCreate()
+    testCoroutineDispatchers.runCurrent()
+    // clearing up all app startup performance metrics: apk size and storage usage.
+    fakePerformanceMetricsEventLogger.clearAllPerformanceMetricsEvents()
+    testCoroutineDispatchers.advanceTimeBy(backgroundCpuLoggingTimePeriodMillis)
+    testCoroutineDispatchers.advanceTimeBy(TimeUnit.MINUTES.toMillis(3))
+    applicationLifecycleObserver.onAppInForeground()
+    testCoroutineDispatchers.runCurrent()
+    testCoroutineDispatchers.advanceTimeBy(foregroundCpuLoggingTimePeriodMillis)
+
+    val count = fakePerformanceMetricsEventLogger.getPerformanceMetricsEventListCount()
+    val events = fakePerformanceMetricsEventLogger.getMostRecentPerformanceMetricsEvents(count)
+
+    assertThat(count).isEqualTo(3)
+    assertThat(events[0].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+    assertThat(events[1].currentScreen).isEqualTo(ScreenName.BACKGROUND_SCREEN)
+    assertThat(events[2].currentScreen).isEqualTo(ScreenName.FOREGROUND_SCREEN)
+  }
+
   private fun setUpTestApplicationComponent() {
     ApplicationProvider.getApplicationContext<TestApplication>().inject(this)
   }

utility/src/main/java/org/oppia/android/util/logging/performancemetrics/PerformanceMetricsAssessor.kt

@@ -73,6 +73,8 @@ interface PerformanceMetricsAssessor {
 
   /** Represents the different states of the application. */
   enum class AppIconification {
+    /** Indicates that the iconification hasn't been initialized yet. */
+    UNINITIALIZED,
     /** Indicates that the app is in foreground. */
     APP_IN_FOREGROUND,
     /** Indicates that the app is in background. */