diff --git a/app/metrics.yaml b/app/metrics.yaml index c47fddb55..5b835aa41 100644 --- a/app/metrics.yaml +++ b/app/metrics.yaml @@ -4194,6 +4194,86 @@ startup.timeline: expires: "2021-08-01" perf.startup: + cold_main_app_to_first_frame: + type: timing_distribution + time_unit: millisecond + description: | + The duration from `*Application`'s initializer to the first Android frame + being drawn in a [COLD MAIN start + up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary). + Notably, this duration omits the time from process start to the + initializer (which includes a lengthy dex operation) and the time from + the first frame to visual completeness. This probe doesn't measure Custom + Tabs or other uses of `ExternalAppBrowserActivity` to simplify result + analysis. The methodology for determining this measurement is imperfect + to simplify implementation. Issues may include: +
- Not measuring Beta and Release channels (due to + `MigrationDecisionActivity` interrupting the logic). +
- Not distinguishing between MAIN to homescreen, onboarding, session + restore, others? +
- Not choosing to record a MAIN based on what the user would see and + thus the core code path (i.e. the thing we want to measure) but rather on + the initial `Intent` state. +

+ The hope is that these cases will not have a significant impact on the end + results but, if they appear to, we can replace it with a more complex + implementation. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/18426 + data_reviews: + - TODO + data_sensitivity: + - technical + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2021-08-11" + cold_view_app_to_first_frame: + type: timing_distribution + time_unit: millisecond + description: | + The duration from `*Application`'s initializer to the first Android frame + being drawn in a [COLD VIEW start + up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary). + The methodology for determining this measurement is imperfect to simplify + implementation. Issues may include: +
-Including VIEW intents that aren't valid so take code paths similar + to MAIN (this is speculative) +

+ See the `cold_main_app_to_first_frame` probe docs for other possible + known issues and more details. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/18426 + data_reviews: + - TODO + data_sensitivity: + - technical + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2021-08-11" + cold_unknwn_app_to_first_frame: + type: timing_distribution + time_unit: millisecond + description: | + The duration from `*Application`'s initializer to the first Android frame + being drawn in a [COLD start + up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary) + where we can't say it was a MAIN or VIEW start up. The methodology for + determining this measurement is imperfect to simplify implementation. +

+ See the `cold_main_app_to_first_frame` probe docs for known issues and + more details. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/18426 + data_reviews: + - TODO + data_sensitivity: + - technical + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2021-08-11" application_on_create: type: timing_distribution time_unit: millisecond diff --git a/app/src/main/java/org/mozilla/fenix/HomeActivity.kt b/app/src/main/java/org/mozilla/fenix/HomeActivity.kt index 5052bb89d..17c276de8 100644 --- a/app/src/main/java/org/mozilla/fenix/HomeActivity.kt +++ b/app/src/main/java/org/mozilla/fenix/HomeActivity.kt @@ -271,6 +271,14 @@ open class HomeActivity : LocaleAwareAppCompatActivity(), NavHostActivity { hasSavedInstanceState, homeActivityInitTimeStampNanoSeconds, rootContainer ) + + components.performance.coldStartupDurationTelemetry.onHomeActivityOnCreate( + components.performance.visualCompletenessQueue, + components.appStartReasonProvider, + components.startupActivityStateProvider, + safeIntent, + rootContainer + ) } override fun onRestart() { diff --git a/app/src/main/java/org/mozilla/fenix/components/PerformanceComponent.kt b/app/src/main/java/org/mozilla/fenix/components/PerformanceComponent.kt index 8f0a677c4..3bbb338b9 100644 --- a/app/src/main/java/org/mozilla/fenix/components/PerformanceComponent.kt +++ b/app/src/main/java/org/mozilla/fenix/components/PerformanceComponent.kt @@ -5,6 +5,7 @@ package org.mozilla.fenix.components import mozilla.components.support.utils.RunWhenReadyQueue +import org.mozilla.fenix.perf.ColdStartupDurationTelemetry import org.mozilla.fenix.perf.VisualCompletenessQueue import org.mozilla.fenix.perf.lazyMonitored @@ -13,4 +14,5 @@ import org.mozilla.fenix.perf.lazyMonitored */ class PerformanceComponent { val visualCompletenessQueue by lazyMonitored { VisualCompletenessQueue(RunWhenReadyQueue()) } + val coldStartupDurationTelemetry by lazyMonitored { ColdStartupDurationTelemetry() } } diff --git a/app/src/main/java/org/mozilla/fenix/customtabs/ExternalAppBrowserActivity.kt b/app/src/main/java/org/mozilla/fenix/customtabs/ExternalAppBrowserActivity.kt index 689a6aa4c..a7546b378 100644 --- a/app/src/main/java/org/mozilla/fenix/customtabs/ExternalAppBrowserActivity.kt +++ b/app/src/main/java/org/mozilla/fenix/customtabs/ExternalAppBrowserActivity.kt @@ -60,6 +60,9 @@ open class ExternalAppBrowserActivity : HomeActivity() { homeActivityInitTimeStampNanoSeconds, rootContainer ) + + // coldStartupDurationTelemetry.onHomeActivityOnCreate is intentionally omitted so we don't + // include even more unpredictable code paths in the results. } override fun navigateToBrowserOnColdStart() { diff --git a/app/src/main/java/org/mozilla/fenix/perf/ColdStartupDurationTelemetry.kt b/app/src/main/java/org/mozilla/fenix/perf/ColdStartupDurationTelemetry.kt new file mode 100644 index 000000000..0ac29a24b --- /dev/null +++ b/app/src/main/java/org/mozilla/fenix/perf/ColdStartupDurationTelemetry.kt @@ -0,0 +1,113 @@ +/* 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.content.Intent +import android.os.SystemClock +import android.view.View +import androidx.core.view.doOnPreDraw +import mozilla.components.support.base.log.logger.Logger +import mozilla.components.support.utils.SafeIntent +import org.mozilla.fenix.GleanMetrics.PerfStartup +import org.mozilla.fenix.perf.StartupActivityStateProvider.FirstForegroundActivity +import org.mozilla.fenix.perf.StartupActivityStateProvider.FirstForegroundActivityState +import org.mozilla.fenix.perf.AppStartReasonProvider.StartReason +import java.util.concurrent.TimeUnit + +private val logger = Logger("ColdStartupDuration") + +/** + * A class to record COLD start up telemetry. This class is intended to improve upon our mistakes from the + * [org.mozilla.fenix.components.metrics.AppStartupTelemetry] class by being simple-to-implement and + * simple-to-analyze (i.e. works in GLAM) rather than being a "perfect" and comprehensive measurement. + * + * This class relies on external state providers like [AppStartReasonProvider] and + * [StartupActivityStateProvider] that are tricky to implement correctly so take the results with a + * grain of salt. + */ +class ColdStartupDurationTelemetry { + + fun onHomeActivityOnCreate( + visualCompletenessQueue: VisualCompletenessQueue, + startReasonProvider: AppStartReasonProvider, + startupActivityStateProvider: StartupActivityStateProvider, + safeIntent: SafeIntent, + rootContainer: View + ) { + // Optimization: it's expensive to post runnables so we can short-circuit with a subset of the later logic. + if (startupActivityStateProvider.firstForegroundActivityState == + FirstForegroundActivityState.AFTER_FOREGROUND) { + logger.debug("Not measuring: first foreground activity already backgrounded") + return + } + + rootContainer.doOnPreDraw { + // Optimization: we're running code before the first frame so we want to avoid doing anything + // expensive as part of the drawing loop. Recording telemetry took 3-7ms on the Moto G5 (a + // frame is ~16ms) so we defer the expensive work for later by posting a Runnable. + // + // We copy the values because their values may change when passed into the handler. It's + // cheaper to copy the values than copy the objects (= allocation + copy values) so we just + // copy the values even though this copy could happen incorrectly if these values become objects later. + val startReason = startReasonProvider.reason + val firstActivity = startupActivityStateProvider.firstForegroundActivityOfProcess + val firstActivityState = startupActivityStateProvider.firstForegroundActivityState + val firstFrameNanos = SystemClock.elapsedRealtimeNanos() + + // On the visual completeness queue, this will report later than posting to the main thread (not + // ideal for pulling out of automated performance tests) but should delay visual completeness less. + visualCompletenessQueue.queue.runIfReadyOrQueue { + if (!isColdStartToThisHomeActivityInstance(startReason, firstActivity, firstActivityState)) { + logger.debug("Not measuring: this activity isn't both the first foregrounded & HomeActivity") + return@runIfReadyOrQueue + } + + recordColdStartupTelemetry(safeIntent, firstFrameNanos) + } + } + } + + private fun isColdStartToThisHomeActivityInstance( + startReason: StartReason, + firstForegroundActivity: FirstForegroundActivity, + firstForegroundActivityState: FirstForegroundActivityState + ): Boolean { + // This logic is fragile: if an Activity that isn't currently foregrounded is refactored to get + // temporarily foregrounded (e.g. IntentReceiverActivity) or an interstitial Activity is added + // that is temporarily foregrounded, we'll no longer detect HomeActivity as the first foregrounded + // activity and we'll never record telemetry. + // + // Because of this, we may not record values in Beta and Release if MigrationDecisionActivity + // gets foregrounded (I never tested these channels: I think Nightly data is probably good enough for now). + // + // What we'd ideally determine is, "Is the final activity during this start up HomeActivity?" + // However, it's challenging to do so in a robust way so we stick with this simpler solution + // ("Is the first foregrounded activity during this start up HomeActivity?") despite its flaws. + val wasProcessStartedBecauseOfAnActivity = startReason == StartReason.ACTIVITY + val isThisTheFirstForegroundActivity = firstForegroundActivity == FirstForegroundActivity.HOME_ACTIVITY && + firstForegroundActivityState == FirstForegroundActivityState.CURRENTLY_FOREGROUNDED + return wasProcessStartedBecauseOfAnActivity && isThisTheFirstForegroundActivity + } + + private fun recordColdStartupTelemetry(safeIntent: SafeIntent, firstFrameNanos: Long) { + // This code duplicates the logic for determining how we should handle this intent which + // could result in inconsistent results: e.g. the browser might get a VIEW intent but it's + // malformed so the app treats it as a MAIN intent but here we record VIEW. However, the + // logic for determining the end state is distributed and buried & inspecting the end state + // is fragile (e.g. if the browser was open, was it a MAIN w/ session restore or VIEW?) so we + // use this simpler solution even if it's imperfect. Hopefully, the success cases will + // outnumber the edge cases into statistical insignificance. + val (metric, typeForLog) = when (safeIntent.action) { + Intent.ACTION_MAIN -> Pair(PerfStartup.coldMainAppToFirstFrame, "MAIN") + Intent.ACTION_VIEW -> Pair(PerfStartup.coldViewAppToFirstFrame, "VIEW") + else -> Pair(PerfStartup.coldUnknwnAppToFirstFrame, "UNKNOWN") + } + + val startNanos = StartupTimeline.frameworkStartMeasurement.applicationInitNanos + val durationMillis = TimeUnit.NANOSECONDS.toMillis(firstFrameNanos - startNanos) + metric.accumulateSamples(longArrayOf(durationMillis)) + logger.info("COLD $typeForLog Application. to first frame: $durationMillis ms") + } +} diff --git a/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt b/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt index a63f0bb61..359ff44f6 100644 --- a/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt +++ b/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt @@ -26,7 +26,8 @@ internal class StartupFrameworkStartMeasurement( private var isMetricSet = false - private var applicationInitNanos = -1L + var applicationInitNanos = -1L + private set private var isApplicationInitCalled = false fun onApplicationInit() { diff --git a/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt b/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt index 2187d8e15..7fb511347 100644 --- a/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt +++ b/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt @@ -40,7 +40,7 @@ object StartupTimeline { private var state: StartupState = StartupState.Cold(StartupDestination.UNKNOWN) private val reportFullyDrawn by lazy { StartupReportFullyDrawn() } - private val frameworkStartMeasurement by lazy { StartupFrameworkStartMeasurement() } + internal val frameworkStartMeasurement by lazy { StartupFrameworkStartMeasurement() } internal val homeActivityLifecycleObserver by lazy { StartupHomeActivityLifecycleObserver(frameworkStartMeasurement) } diff --git a/docs/metrics.md b/docs/metrics.md index d78df39fe..cef175232 100644 --- a/docs/metrics.md +++ b/docs/metrics.md @@ -351,6 +351,9 @@ In addition to those built-in metrics, the following metrics are added to the pi | perf.startup.application_on_create |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `FenixApplication.onCreate` in the main process. This does not measure the duration of migration code (via `MigratingFenixApplication` included in the Beta and Release channels. |[mozilla-mobile/fenix#17973](https://github.com/mozilla-mobile/fenix/pull/17973#issue-572183889)||2021-08-11 |1 | | perf.startup.base_bfragment_on_create_view |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `BaseBrowserFragment.onCreateView`. |[mozilla-mobile/fenix#18558](https://github.com/mozilla-mobile/fenix/pull/18558#issue-596791848)||2021-08-11 |1 | | perf.startup.base_bfragment_on_view_created |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `BaseBrowserFragment.onViewCreated`. |[mozilla-mobile/fenix#18558](https://github.com/mozilla-mobile/fenix/pull/18558#issue-596791848)||2021-08-11 |1 | +| perf.startup.cold_main_app_to_first_frame |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration from `*Application`'s initializer to the first Android frame being drawn in a [COLD MAIN start up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary). Notably, this duration omits the time from process start to the initializer (which includes a lengthy dex operation) and the time from the first frame to visual completeness. This probe doesn't measure Custom Tabs or other uses of `ExternalAppBrowserActivity` to simplify result analysis. The methodology for determining this measurement is imperfect to simplify implementation. Issues may include:
- Not measuring Beta and Release channels (due to `MigrationDecisionActivity` interrupting the logic).
- Not distinguishing between MAIN to homescreen, onboarding, session restore, others?
- Not choosing to record a MAIN based on what the user would see and thus the core code path (i.e. the thing we want to measure) but rather on the initial `Intent` state.

The hope is that these cases will not have a significant impact on the end results but, if they appear to, we can replace it with a more complex implementation. |[Review 1](TODO)||2021-08-11 |1 | +| perf.startup.cold_unknwn_app_to_first_frame |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration from `*Application`'s initializer to the first Android frame being drawn in a [COLD start up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary) where we can't say it was a MAIN or VIEW start up. The methodology for determining this measurement is imperfect to simplify implementation.

See the `cold_main_app_to_first_frame` probe docs for known issues and more details. |[Review 1](TODO)||2021-08-11 |1 | +| perf.startup.cold_view_app_to_first_frame |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration from `*Application`'s initializer to the first Android frame being drawn in a [COLD VIEW start up](https://wiki.mozilla.org/index.php?title=Performance/Fenix/Glossary). The methodology for determining this measurement is imperfect to simplify implementation. Issues may include:
-Including VIEW intents that aren't valid so take code paths similar to MAIN (this is speculative)

See the `cold_main_app_to_first_frame` probe docs for other possible known issues and more details. |[Review 1](TODO)||2021-08-11 |1 | | perf.startup.home_activity_on_create |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `HomeActivity.onCreate`. |[mozilla-mobile/fenix#17973](https://github.com/mozilla-mobile/fenix/pull/17973#issue-572183889)||2021-08-11 |1 | | perf.startup.home_activity_on_start |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `HomeActivity.onStart`. This may encapsulate `HomeFragment` or `BrowserFragment` creation, depending on the code path, so we expect this to take varying amounts of time. As such, this probe may not be easy to interpret directly but we believe collecting it may give us more information about different patterns we might see in performance data. |[mozilla-mobile/fenix#18558](https://github.com/mozilla-mobile/fenix/pull/18558#issue-596791848)||2021-08-11 |1 | | perf.startup.home_fragment_on_create_view |[timing_distribution](https://mozilla.github.io/glean/book/user/metrics/timing_distribution.html) |The duration of `HomeFragment.onCreateView`. |[mozilla-mobile/fenix#18558](https://github.com/mozilla-mobile/fenix/pull/18558#issue-596791848)||2021-08-11 |1 |