For #18426: record cold start duration telemetry.

upstream-sync
Michael Comella 3 years ago committed by Michael Comella
parent 2be9fb61d0
commit ade38246be

@ -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:
<br>- Not measuring Beta and Release channels (due to
`MigrationDecisionActivity` interrupting the logic).
<br>- Not distinguishing between MAIN to homescreen, onboarding, session
restore, others?
<br>- 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.
<br><br>
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:
<br>-Including VIEW intents that aren't valid so take code paths similar
to MAIN (this is speculative)
<br><br>
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.
<br><br>
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

@ -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() {

@ -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() }
}

@ -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() {

@ -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.<init> to first frame: $durationMillis ms")
}
}

@ -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() {

@ -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)
}

@ -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: <br>- Not measuring Beta and Release channels (due to `MigrationDecisionActivity` interrupting the logic). <br>- Not distinguishing between MAIN to homescreen, onboarding, session restore, others? <br>- 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. <br><br> 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. <br><br> 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: <br>-Including VIEW intents that aren't valid so take code paths similar to MAIN (this is speculative) <br><br> 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 |

Loading…
Cancel
Save