diff --git a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt index a4e802678a..c5b520cd5f 100644 --- a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt +++ b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt @@ -194,6 +194,7 @@ open class FenixApplication : LocaleAwareApplication(), Provider { components.appStartReasonProvider.registerInAppOnCreate(this) components.startupActivityStateProvider.registerInAppOnCreate(this) + components.startupActivityLog.registerInAppOnCreate(this) initVisualCompletenessQueueAndQueueTasks() ProcessLifecycleOwner.get().lifecycle.addObserver(TelemetryLifecycleObserver(components.core.store)) diff --git a/app/src/main/java/org/mozilla/fenix/components/Components.kt b/app/src/main/java/org/mozilla/fenix/components/Components.kt index 1a0a48f360..3a2fa03e46 100644 --- a/app/src/main/java/org/mozilla/fenix/components/Components.kt +++ b/app/src/main/java/org/mozilla/fenix/components/Components.kt @@ -29,6 +29,7 @@ import org.mozilla.fenix.components.metrics.AppStartupTelemetry import org.mozilla.fenix.ext.components import org.mozilla.fenix.ext.settings import org.mozilla.fenix.perf.AppStartReasonProvider +import org.mozilla.fenix.perf.StartupActivityLog import org.mozilla.fenix.perf.StartupActivityStateProvider import org.mozilla.fenix.perf.lazyMonitored import org.mozilla.fenix.utils.ClipboardHandler @@ -176,4 +177,5 @@ class Components(private val context: Context) { val appStartReasonProvider by lazyMonitored { AppStartReasonProvider() } val startupActivityStateProvider by lazyMonitored { StartupActivityStateProvider() } + val startupActivityLog by lazyMonitored { StartupActivityLog() } } diff --git a/app/src/main/java/org/mozilla/fenix/perf/StartupActivityLog.kt b/app/src/main/java/org/mozilla/fenix/perf/StartupActivityLog.kt new file mode 100644 index 0000000000..e841bf8a66 --- /dev/null +++ b/app/src/main/java/org/mozilla/fenix/perf/StartupActivityLog.kt @@ -0,0 +1,100 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +package org.mozilla.fenix.perf + +import android.app.Activity +import android.app.Application +import android.os.Bundle +import androidx.annotation.VisibleForTesting +import androidx.annotation.VisibleForTesting.NONE +import androidx.annotation.VisibleForTesting.PRIVATE +import androidx.lifecycle.DefaultLifecycleObserver +import androidx.lifecycle.LifecycleOwner +import androidx.lifecycle.ProcessLifecycleOwner +import mozilla.components.support.base.log.Log +import mozilla.components.support.base.log.logger.Logger +import org.mozilla.fenix.android.DefaultActivityLifecycleCallbacks + +private val logger = Logger("StartupActivityLog") + +/** + * A record of the [Activity] created, started, and stopped events as well as [Application] + * foreground and background events. See [log] for the log. This class is expected to be + * registered in [Application.onCreate] by calling [registerInAppOnCreate]. + */ +class StartupActivityLog { + + private val _log = mutableListOf() + val log: List = _log + + fun registerInAppOnCreate( + application: Application, + processLifecycleOwner: LifecycleOwner = ProcessLifecycleOwner.get() + ) { + processLifecycleOwner.lifecycle.addObserver(StartupLogAppLifecycleObserver()) + application.registerActivityLifecycleCallbacks(StartupLogActivityLifecycleCallbacks()) + } + + @VisibleForTesting(otherwise = NONE) + fun getObserversForTesting() = Pair(StartupLogAppLifecycleObserver(), StartupLogActivityLifecycleCallbacks()) + + @VisibleForTesting(otherwise = PRIVATE) + fun logEntries(loggerArg: Logger = logger, logLevel: Log.Priority = Log.logLevel) { + // Optimization: we want to avoid the potentially expensive conversions + // to Strings if we're not going to log anyway. + if (logLevel > Log.Priority.DEBUG) { + return + } + + val transformedEntries = log.map { when (it) { + is LogEntry.AppStarted -> "App-STARTED" + is LogEntry.AppStopped -> "App-STOPPED" + is LogEntry.CreatedActivityLogEntry -> "${it.activityClass.simpleName}-CREATED" + is LogEntry.StartedActivityLogEntry -> "${it.activityClass.simpleName}-STARTED" + is LogEntry.StoppedActivityLogEntry -> "${it.activityClass.simpleName}-STOPPED" + } } + + loggerArg.debug(transformedEntries.toString()) + } + + @VisibleForTesting(otherwise = PRIVATE) + inner class StartupLogAppLifecycleObserver : DefaultLifecycleObserver { + override fun onStart(owner: LifecycleOwner) { + _log.add(LogEntry.AppStarted) + } + + override fun onStop(owner: LifecycleOwner) { + _log.add(LogEntry.AppStopped) + logEntries() + } + } + + @VisibleForTesting(otherwise = PRIVATE) + inner class StartupLogActivityLifecycleCallbacks : DefaultActivityLifecycleCallbacks { + override fun onActivityCreated(activity: Activity, bundle: Bundle?) { + _log.add(LogEntry.CreatedActivityLogEntry(activity::class.java)) + } + + override fun onActivityStarted(activity: Activity) { + _log.add(LogEntry.StartedActivityLogEntry(activity::class.java)) + } + + override fun onActivityStopped(activity: Activity) { + _log.add(LogEntry.StoppedActivityLogEntry(activity::class.java)) + } + } + + /** + * A log entry with its detailed information for the [StartupActivityLog]. + */ + sealed class LogEntry { + object AppStarted : LogEntry() + object AppStopped : LogEntry() + + data class CreatedActivityLogEntry(val activityClass: Class) : LogEntry() + data class StartedActivityLogEntry(val activityClass: Class) : LogEntry() + data class StoppedActivityLogEntry(val activityClass: Class) : LogEntry() + } +} diff --git a/app/src/test/java/org/mozilla/fenix/perf/StartupActivityLogTest.kt b/app/src/test/java/org/mozilla/fenix/perf/StartupActivityLogTest.kt new file mode 100644 index 0000000000..09c2d54c16 --- /dev/null +++ b/app/src/test/java/org/mozilla/fenix/perf/StartupActivityLogTest.kt @@ -0,0 +1,95 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +package org.mozilla.fenix.perf + +import android.app.Activity +import android.app.Application +import androidx.lifecycle.LifecycleOwner +import io.mockk.Called +import io.mockk.MockKAnnotations +import io.mockk.impl.annotations.MockK +import io.mockk.mockk +import io.mockk.verify +import mozilla.components.support.base.log.Log.Priority +import mozilla.components.support.base.log.logger.Logger +import org.junit.Assert.assertEquals +import org.junit.Assert.assertTrue +import org.junit.Before +import org.junit.Test +import org.mozilla.fenix.perf.StartupActivityLog.LogEntry + +class StartupActivityLogTest { + + private lateinit var log: StartupActivityLog + private lateinit var appObserver: StartupActivityLog.StartupLogAppLifecycleObserver + private lateinit var activityCallbacks: StartupActivityLog.StartupLogActivityLifecycleCallbacks + @MockK(relaxed = true) private lateinit var logger: Logger + + @Before + fun setUp() { + MockKAnnotations.init(this) + + log = StartupActivityLog() + val (appObserver, activityCallbacks) = log.getObserversForTesting() + this.appObserver = appObserver + this.activityCallbacks = activityCallbacks + } + + @Test + fun `WHEN register is called THEN it is registered`() { + val app = mockk(relaxed = true) + val lifecycleOwner = mockk(relaxed = true) + log.registerInAppOnCreate(app, lifecycleOwner) + + verify { app.registerActivityLifecycleCallbacks(any()) } + verify { lifecycleOwner.lifecycle.addObserver(any()) } + } + + @Test // we test start and stop individually due to the clear-on-stop behavior. + fun `WHEN app observer start is called THEN it is added directly to the log`() { + assertTrue(log.log.isEmpty()) + val expected = mutableListOf() + + appObserver.onStart(mockk()) + expected.add(LogEntry.AppStarted) + assertEquals(expected, log.log) + + appObserver.onStop(mockk()) + expected.add(LogEntry.AppStopped) + assertEquals(expected, log.log) + } + + @Test + fun `WHEN activity callback methods are called THEN they are added directly to the log`() { + assertTrue(log.log.isEmpty()) + val expected = mutableListOf() + + val activityClass = mockk()::class.java // mockk can't mock Class<...> + + activityCallbacks.onActivityCreated(mockk(), null) + expected.add(LogEntry.CreatedActivityLogEntry(activityClass)) + assertEquals(expected, log.log) + + activityCallbacks.onActivityStarted(mockk()) + expected.add(LogEntry.StartedActivityLogEntry(activityClass)) + assertEquals(expected, log.log) + + activityCallbacks.onActivityStopped(mockk()) + expected.add(LogEntry.StoppedActivityLogEntry(activityClass)) + assertEquals(expected, log.log) + } + + @Test + fun `GIVEN debug log level WHEN logEntries is called THEN there is no logcat call`() { + log.logEntries(logger, Priority.DEBUG) + verify { logger.debug(any()) } + } + + @Test + fun `GIVEN info log level WHEN logEntries is called THEN there is a logcat call`() { + log.logEntries(logger, Priority.INFO) + verify { logger wasNot Called } + } +}