diff --git a/app/metrics.yaml b/app/metrics.yaml index 6888884801fe..d69a9a9037a2 100644 --- a/app/metrics.yaml +++ b/app/metrics.yaml @@ -1984,3 +1984,57 @@ addons: notification_emails: - fenix-core@mozilla.com expires: "2020-09-01" + +startup.timeline: + framework_start: + send_in_pings: + - startup-timeline + type: timespan + time_unit: nanosecond + description: > + The duration the Android framework takes to start before letting us run code in + `*Application.init`. This is calculated from `appInitTimestamp - processStartTimestamp`. + `processStartTimestamp` is derived from the clock tick time unit, which is expected to be + less granular than nanoseconds. Therefore, we convert and round our timestamps to clock ticks + before computing the difference and convert back to nanoseconds to report. + + For debugging purposes, `clock_ticks_per_second`, which may vary between devices, is also + reported as a metric. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/8803 + data_reviews: + - https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626 + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2020-07-15" + framework_start_error: + send_in_pings: + - startup-timeline + type: boolean + description: > + An error when attempting to record `framework_start` - the application init timestamp returned + a negative value - which is likely indicative of a bug in the implementation. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/8803 + data_reviews: + - https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626 + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2020-07-15" + clock_ticks_per_second: + send_in_pings: + - startup-timeline + type: counter + description: > + The number of clock tick time units that occur in one second on this particular device. This + value is expected to be used in conjunction with the `framework_start` metric. + bugs: + - https://github.com/mozilla-mobile/fenix/issues/8803 + data_reviews: + - https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626 + notification_emails: + - perf-android-fe@mozilla.com + - mcomella@mozilla.com + expires: "2020-07-15" diff --git a/app/pings.yaml b/app/pings.yaml index 3083e9ab017a..c31555476827 100644 --- a/app/pings.yaml +++ b/app/pings.yaml @@ -29,3 +29,19 @@ installation: - https://github.com/mozilla-mobile/fenix/pull/8074#issuecomment-586512202 notification_emails: - fenix-core@mozilla.com + +startup-timeline: + description: > + This ping is intended to provide an understanding of startup performance. + + The ping is intended to be captured by performance testing automation to report results + there, in addition to user telemetry. We place these metrics into their own ping in order + to isolate them and make this process easier. + include_client_id: false + bugs: + - https://github.com/mozilla-mobile/fenix/issues/8803 + data_reviews: + - https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626 + notification_emails: + - perf-android-fe@mozilla.com + - esmyth@mozilla.com diff --git a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt index 8753ce6ebcc8..3d607eb7aaf9 100644 --- a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt +++ b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt @@ -38,6 +38,7 @@ import org.mozilla.fenix.FeatureFlags.webPushIntegration import org.mozilla.fenix.components.Components import org.mozilla.fenix.components.metrics.MetricServiceType import org.mozilla.fenix.ext.settings +import org.mozilla.fenix.perf.StartupTimeline import org.mozilla.fenix.push.PushFxaIntegration import org.mozilla.fenix.push.WebPushEngineIntegration import org.mozilla.fenix.session.NotificationSessionObserver @@ -49,6 +50,10 @@ import org.mozilla.fenix.utils.Settings @SuppressLint("Registered") @Suppress("TooManyFunctions", "LargeClass") open class FenixApplication : LocaleAwareApplication() { + init { + recordOnInit() // DO NOT MOVE ANYTHING ABOVE HERE: the timing of this measurement is critical. + } + private val logger = Logger("FenixApplication") open val components by lazy { Components(this) } @@ -365,4 +370,12 @@ open class FenixApplication : LocaleAwareApplication() { Logger.error("Failed to initialize web extension support", e) } } + + protected fun recordOnInit() { + // This gets called by more than one process. Ideally we'd only run this in the main process + // but the code to check which process we're in crashes because the Context isn't valid yet. + // + // This method is not covered by our internal crash reporting: be very careful when modifying it. + StartupTimeline.onApplicationInit() // DO NOT MOVE ANYTHING ABOVE HERE: the timing is critical. + } } diff --git a/app/src/main/java/org/mozilla/fenix/HomeActivity.kt b/app/src/main/java/org/mozilla/fenix/HomeActivity.kt index 627826a3aede..30c897e581bc 100644 --- a/app/src/main/java/org/mozilla/fenix/HomeActivity.kt +++ b/app/src/main/java/org/mozilla/fenix/HomeActivity.kt @@ -33,6 +33,7 @@ import mozilla.components.concept.engine.EngineView import mozilla.components.feature.contextmenu.ext.DefaultSelectionActionDelegate import mozilla.components.service.fxa.sync.SyncReason import mozilla.components.support.base.feature.UserInteractionHandler +import mozilla.components.support.ktx.android.arch.lifecycle.addObservers import mozilla.components.support.ktx.android.content.share import mozilla.components.support.ktx.kotlin.isUrl import mozilla.components.support.ktx.kotlin.toNormalizedUrl @@ -146,7 +147,10 @@ open class HomeActivity : LocaleAwareAppCompatActivity() { } supportActionBar?.hide() - lifecycle.addObserver(webExtensionPopupFeature) + lifecycle.addObservers( + webExtensionPopupFeature, + StartupTimeline.homeActivityLifecycleObserver + ) StartupTimeline.onActivityCreateEndHome(this) } diff --git a/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt b/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt new file mode 100644 index 000000000000..5a3fe8923ac3 --- /dev/null +++ b/app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt @@ -0,0 +1,86 @@ +/* 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.os.Process +import android.os.SystemClock +import kotlin.math.roundToLong +import org.mozilla.fenix.GleanMetrics.StartupTimeline as Telemetry + +/** + * A class to measure the time the Android framework executes before letting us execute our own code + * for the first time in Application's initializer: this value is captured in the + * [Telemetry.frameworkStart] probe. + * + * Since we cannot execute code at process start, this measurement does not fit within the Glean + * Timespan metric start/stop programming model so it lives in its own class. + */ +internal class StartupFrameworkStartMeasurement( + private val stat: Stat = Stat(), + private val telemetry: Telemetry = Telemetry, + private val getElapsedRealtimeNanos: () -> Long = SystemClock::elapsedRealtimeNanos +) { + + private var isMetricSet = false + + private var applicationInitNanos = -1L + private var isApplicationInitCalled = false + + fun onApplicationInit() { + // This gets called from multiple processes: don't do anything expensive. See call site for details. + // + // In the main process, there are multiple Application impl so we ensure it's only set by + // the first one. + if (!isApplicationInitCalled) { + isApplicationInitCalled = true + applicationInitNanos = getElapsedRealtimeNanos() + } + } + + /** + * Sets the values for metrics to record in glean. + * + * We defer these metrics, rather than setting them as soon as the values are available, + * because they are slow to fetch and we don't want to impact startup. + */ + fun setExpensiveMetric() { + // The application is only init once per process lifetime so we only set this value once. + if (isMetricSet) return + isMetricSet = true + + if (applicationInitNanos < 0) { + telemetry.frameworkStartError.set(true) + } else { + telemetry.frameworkStart.setRawNanos(getFrameworkStartNanos()) + + // frameworkStart is derived from the number of clock ticks per second. To ensure this + // value does not throw off our result, we capture it too. + telemetry.clockTicksPerSecond.add(stat.clockTicksPerSecond.toInt()) + } + } + + private fun getFrameworkStartNanos(): Long { + // Get our timestamps in ticks: we expect ticks to be less granular than nanoseconds so, + // to ensure our measurement uses the correct number of significant figures, we convert + // everything to ticks before getting the result. + // + // Similarly, we round app init to a whole integer tick value because process start only + // comes in integer ticks values. + val processStartTicks = stat.getProcessStartTimeTicks(Process.myPid()) + val applicationInitTicks = applicationInitNanos.nanosToTicks().roundToLong() + + val frameworkStartTicks = applicationInitTicks - processStartTicks + + // Glean only takes whole unit nanoseconds so we round to that. I'm not sure but it may be + // possible that capturing nanos in a double will produce a rounding error that chops off + // significant values. However, since we expect to be using a much smaller portion of the + // nano field - if ticks are actually less granular than nanoseconds - I don't expect for + // this to be a problem. + return frameworkStartTicks.ticksToNanos().roundToLong() + } + + private fun Long.nanosToTicks(): Double = stat.convertNanosToTicks(this) + private fun Long.ticksToNanos(): Double = stat.convertTicksToNanos(this) +} 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 f2561476b5ed..8a8f45cfa33e 100644 --- a/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt +++ b/app/src/main/java/org/mozilla/fenix/perf/StartupTimeline.kt @@ -5,8 +5,17 @@ package org.mozilla.fenix.perf import androidx.annotation.UiThread +import androidx.lifecycle.Lifecycle +import androidx.lifecycle.LifecycleObserver +import androidx.lifecycle.OnLifecycleEvent +import kotlinx.coroutines.GlobalScope +import kotlinx.coroutines.launch +import mozilla.components.service.glean.private.NoReasonCodes +import mozilla.components.service.glean.private.PingType +import org.mozilla.fenix.GleanMetrics.Pings import org.mozilla.fenix.HomeActivity import org.mozilla.fenix.home.sessioncontrol.viewholders.topsites.TopSiteItemViewHolder +import org.mozilla.fenix.perf.StartupTimeline.onApplicationInit import org.mozilla.fenix.perf.StartupTimelineStateMachine.StartupActivity import org.mozilla.fenix.perf.StartupTimelineStateMachine.StartupDestination import org.mozilla.fenix.perf.StartupTimelineStateMachine.StartupState @@ -20,12 +29,27 @@ import org.mozilla.fenix.perf.StartupTimelineStateMachine.StartupState * This class, and its dependencies, may need to be modified for any changes in startup. * * This class is not thread safe and should only be called from the main thread. + * + * [onApplicationInit] is called from multiple processes. To minimize overhead, the class + * dependencies are lazily initialized. */ @UiThread object StartupTimeline { private var state: StartupState = StartupState.Cold(StartupDestination.UNKNOWN) - private val reportFullyDrawn = StartupReportFullyDrawn() + + private val reportFullyDrawn by lazy { StartupReportFullyDrawn() } + private val frameworkStartMeasurement by lazy { StartupFrameworkStartMeasurement() } + internal val homeActivityLifecycleObserver by lazy { + StartupHomeActivityLifecycleObserver(frameworkStartMeasurement) + } + + fun onApplicationInit() { + // This gets called from multiple processes: don't do anything expensive. See call site for details. + // + // This method also gets called multiple times if there are multiple Application implementations. + frameworkStartMeasurement.onApplicationInit() + } fun onActivityCreateEndIntentReceiver() { advanceState(StartupActivity.INTENT_RECEIVER) @@ -45,3 +69,29 @@ object StartupTimeline { state = StartupTimelineStateMachine.getNextState(state, startingActivity) } } + +/** + * A [LifecycleObserver] for [HomeActivity] focused on startup performance measurement. + */ +internal class StartupHomeActivityLifecycleObserver( + private val frameworkStartMeasurement: StartupFrameworkStartMeasurement, + private val startupTimeline: PingType = Pings.startupTimeline +) : LifecycleObserver { + + @OnLifecycleEvent(Lifecycle.Event.ON_STOP) + fun onStop() { + GlobalScope.launch { // use background thread due to expensive metrics. + // Ensure any last metrics are set before submission. + frameworkStartMeasurement.setExpensiveMetric() + + // Startup metrics placed in the Activity should be re-recorded each time the Activity + // is started so we need to clear the ping lifetime by submitting once per each startup. + // It's less complex to add it here rather than the visual completeness task manager. + // + // N.B.: this submission location may need to be changed if we add metrics outside of the + // HomeActivity startup path (e.g. if the user goes directly to a separate activity and + // closes the app, they will never hit this) to appropriately adjust for the ping lifetimes. + startupTimeline.submit() + } + } +} diff --git a/app/src/main/java/org/mozilla/fenix/perf/Stat.kt b/app/src/main/java/org/mozilla/fenix/perf/Stat.kt new file mode 100644 index 000000000000..a2ff22b53b18 --- /dev/null +++ b/app/src/main/java/org/mozilla/fenix/perf/Stat.kt @@ -0,0 +1,66 @@ +/* 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.os.SystemClock +import android.system.Os +import android.system.OsConstants +import androidx.annotation.VisibleForTesting +import androidx.annotation.VisibleForTesting.PRIVATE +import java.io.File +import java.util.concurrent.TimeUnit + +private const val FIELD_POS_STARTTIME = 21 // starttime naming matches field in man page. + +/** + * Functionality from stat on the proc pseudo-filesystem common to unix systems. /proc contains + * information related to active processes. /proc/$pid/stat contains information about the status of + * the process by the given process id (pid). + * + * See the man page - `man 5 proc` - on linux for more information: + * http://man7.org/linux/man-pages/man5/proc.5.html + */ +open class Stat { + + @VisibleForTesting(otherwise = PRIVATE) + open fun getStatText(pid: Int): String = File("/proc/$pid/stat").readText() + + // See `man 3 sysconf` for details on Os.sysconf and OsConstants: + // http://man7.org/linux/man-pages/man3/sysconf.3.html + open val clockTicksPerSecond: Long get() = Os.sysconf(OsConstants._SC_CLK_TCK) + private val nanosPerClockTick = TimeUnit.SECONDS.toNanos(1).let { nanosPerSecond -> + // We use nanos per clock tick, rather than clock ticks per nanos, to mitigate float/double + // rounding errors: this way we can use integer values and divide the larger value by the smaller one. + nanosPerSecond / clockTicksPerSecond.toDouble() + } + + /** + * Gets the process start time since system boot in ticks, including time spent in suspension/deep sleep. + * This value can be compared against [SystemClock.elapsedRealtimeNanos]: you can convert between + * measurements using [convertTicksToNanos] and [convertNanosToTicks]. + * + * Ticks are "an arbitrary unit for measuring internal system time": https://superuser.com/a/101202 + * They are not aligned with CPU frequency and do not change at runtime but can theoretically + * change between devices. On the Pixel 2, one tick is equivalent to one centisecond. + * + * We confirmed that this measurement and elapsedRealtimeNanos both include suspension time, and + * are thus comparable, by* looking at their source: + * - /proc/pid/stat starttime is set using boottime: + * https://github.com/torvalds/linux/blob/79e178a57dae819ae724065b47c25720494cc9f2/fs/proc/array.c#L536 + * - elapsedRealtimeNanos is set using boottime: + * https://cs.android.com/android/platform/superproject/+/master:system/core/libutils/SystemClock.cpp;l=60-68;drc=bab16584ce0525742b5370682c9132b2002ee110 + * + * Perf note: this call reads from the pseudo-filesystem using the java File APIs, which isn't + * likely to be a very optimized call path. + * + * Implementation inspired by https://stackoverflow.com/a/42195623. + */ + fun getProcessStartTimeTicks(pid: Int): Long { + return getStatText(pid).split(' ')[FIELD_POS_STARTTIME].toLong() + } + + fun convertTicksToNanos(ticks: Long): Double = ticks * nanosPerClockTick + fun convertNanosToTicks(nanos: Long): Double = nanos / nanosPerClockTick +} diff --git a/app/src/migration/java/org/mozilla/fenix/MigratingFenixApplication.kt b/app/src/migration/java/org/mozilla/fenix/MigratingFenixApplication.kt index 25864344832b..f6de4e5211e1 100644 --- a/app/src/migration/java/org/mozilla/fenix/MigratingFenixApplication.kt +++ b/app/src/migration/java/org/mozilla/fenix/MigratingFenixApplication.kt @@ -13,8 +13,9 @@ import org.mozilla.fenix.session.PerformanceActivityLifecycleCallbacks * An application class which knows how to migrate Fennec data. */ class MigratingFenixApplication : FenixApplication() { - init { + recordOnInit() // DO NOT MOVE ANYTHING ABOVE HERE: the timing of this measurement is critical. + PerformanceActivityLifecycleCallbacks.isTransientActivityInMigrationVariant = { if (it is MigrationDecisionActivity) true else false } diff --git a/app/src/test/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurementTest.kt b/app/src/test/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurementTest.kt new file mode 100644 index 000000000000..7fadf1f2854f --- /dev/null +++ b/app/src/test/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurementTest.kt @@ -0,0 +1,117 @@ +/* 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 io.mockk.Called +import io.mockk.MockKAnnotations +import io.mockk.every +import io.mockk.impl.annotations.MockK +import io.mockk.spyk +import io.mockk.verify +import mozilla.components.service.glean.private.BooleanMetricType +import mozilla.components.service.glean.private.CounterMetricType +import mozilla.components.service.glean.private.TimespanMetricType +import org.junit.Before +import org.junit.Test +import org.mozilla.fenix.GleanMetrics.StartupTimeline as Telemetry + +private const val CLOCK_TICKS_PER_SECOND = 100L + +class StartupFrameworkStartMeasurementTest { + + private lateinit var metrics: StartupFrameworkStartMeasurement + private lateinit var stat: Stat + + // We'd prefer to use the Glean test methods over these mocks but they require us to add + // Robolectric and it's not worth the impact on test duration. + @MockK private lateinit var telemetry: Telemetry + @MockK(relaxed = true) private lateinit var frameworkStart: TimespanMetricType + @MockK(relaxed = true) private lateinit var frameworkStartError: BooleanMetricType + @MockK(relaxed = true) private lateinit var clockTicksPerSecond: CounterMetricType + + private var elapsedRealtimeNanos = -1L + private var processStartTimeTicks = -1L + + @Before + fun setUp() { + MockKAnnotations.init(this) + + elapsedRealtimeNanos = -1 + processStartTimeTicks = -1 + + stat = spyk(object : Stat() { + override val clockTicksPerSecond: Long get() = CLOCK_TICKS_PER_SECOND + }) + every { stat.getProcessStartTimeTicks(any()) } answers { processStartTimeTicks } + val getElapsedRealtimeNanos = { elapsedRealtimeNanos } + + every { telemetry.frameworkStart } returns frameworkStart + every { telemetry.frameworkStartError } returns frameworkStartError + every { telemetry.clockTicksPerSecond } returns clockTicksPerSecond + + metrics = StartupFrameworkStartMeasurement(stat, telemetry, getElapsedRealtimeNanos) + } + + @Test + fun `GIVEN app init is invalid WHEN metrics are set THEN frameworkStartError is set to true`() { + setProcessAppInitAndMetrics(processStart = 10, appInit = -1) + verifyFrameworkStartError() + } + + @Test + fun `GIVEN app init is not called WHEN metrics are set THEN frameworkStartError is set to true`() { + metrics.setExpensiveMetric() + verifyFrameworkStartError() + } + + @Test + fun `GIVEN app init is set to valid values WHEN metrics are set THEN frameworkStart is set with the correct value`() { + setProcessAppInitAndMetrics(processStart = 166_636_813, appInit = 1_845_312_345_673_925) + verifyFrameworkStartSuccess(178_944_220_000_000) // calculated by hand. + } + + @Test // this overlaps with the success case test. + fun `GIVEN app init has valid values WHEN onAppInit is called twice and metrics are set THEN frameworkStart uses the first app init value`() { + processStartTimeTicks = 166_636_813 + + elapsedRealtimeNanos = 1_845_312_345_673_925 + metrics.onApplicationInit() + elapsedRealtimeNanos = 1_945_312_345_673_925 + metrics.onApplicationInit() + + metrics.setExpensiveMetric() + verifyFrameworkStartSuccess(178_944_220_000_000) // calculated by hand. + } + + @Test + fun `GIVEN app init have valid values WHEN metrics are set twice THEN frameworkStart is only set once`() { + setProcessAppInitAndMetrics(10, 100) + metrics.setExpensiveMetric() + verify(exactly = 1) { frameworkStart.setRawNanos(any()) } + verify(exactly = 1) { clockTicksPerSecond.add(any()) } + verify { frameworkStartError wasNot Called } + } + + private fun setProcessAppInitAndMetrics(processStart: Long, appInit: Long) { + processStartTimeTicks = processStart + + elapsedRealtimeNanos = appInit + metrics.onApplicationInit() + + metrics.setExpensiveMetric() + } + + private fun verifyFrameworkStartSuccess(nanos: Long) { + verify { frameworkStart.setRawNanos(nanos) } + verify { clockTicksPerSecond.add(CLOCK_TICKS_PER_SECOND.toInt()) } + verify { frameworkStartError wasNot Called } + } + + private fun verifyFrameworkStartError() { + verify { frameworkStartError.set(true) } + verify { frameworkStart wasNot Called } + verify { clockTicksPerSecond wasNot Called } + } +} diff --git a/app/src/test/java/org/mozilla/fenix/perf/StartupHomeActivityLifecycleObserverTest.kt b/app/src/test/java/org/mozilla/fenix/perf/StartupHomeActivityLifecycleObserverTest.kt new file mode 100644 index 000000000000..7d4203c4053c --- /dev/null +++ b/app/src/test/java/org/mozilla/fenix/perf/StartupHomeActivityLifecycleObserverTest.kt @@ -0,0 +1,38 @@ +/* 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 io.mockk.MockKAnnotations +import io.mockk.impl.annotations.MockK +import io.mockk.verifySequence +import kotlinx.coroutines.ExperimentalCoroutinesApi +import kotlinx.coroutines.test.runBlockingTest +import mozilla.components.service.glean.private.NoReasonCodes +import mozilla.components.service.glean.private.PingType +import org.junit.Before +import org.junit.Test + +@ExperimentalCoroutinesApi +class StartupHomeActivityLifecycleObserverTest { + + private lateinit var observer: StartupHomeActivityLifecycleObserver + @MockK(relaxed = true) private lateinit var frameworkStartMeasurement: StartupFrameworkStartMeasurement + @MockK(relaxed = true) private lateinit var startupTimeline: PingType + + @Before + fun setUp() { + MockKAnnotations.init(this) + observer = StartupHomeActivityLifecycleObserver(frameworkStartMeasurement, startupTimeline) + } + + @Test + fun `WHEN onStop is called THEN the metrics are set and the ping is submitted`() = runBlockingTest { + observer.onStop() + verifySequence { + frameworkStartMeasurement.setExpensiveMetric() + startupTimeline.submit() + } + } +} diff --git a/app/src/test/java/org/mozilla/fenix/perf/StatTest.kt b/app/src/test/java/org/mozilla/fenix/perf/StatTest.kt new file mode 100644 index 000000000000..aed5e6c71ec6 --- /dev/null +++ b/app/src/test/java/org/mozilla/fenix/perf/StatTest.kt @@ -0,0 +1,45 @@ +/* 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 org.junit.Assert.assertEquals +import org.junit.Before +import org.junit.Test + +private const val STAT_CONTENTS = "32250 (a.fennec_aurora) S 831 831 0 0 -1 1077952832 670949 0 184936 0 15090 5387 0 0 20 0 119 0 166636813 9734365184 24664 18446744073709551615 1 1 0 0 0 0 4612 4097 1073792254 0 0 0 17 1 0 0 0 0 0 0 0 0 0 0 0 0 0" +private const val CLOCK_TICKS_PER_SECOND = 100L // actual value on the Pixel 2. + +class StatTest { + + private lateinit var stat: StatTestImpl + + @Before + fun setUp() { + stat = StatTestImpl() + } + + @Test + fun `WHEN getting the process start time THEN the correct value is returned`() { + val actual = stat.getProcessStartTimeTicks(pid = -1) // pid behavior is overridden. + assertEquals(166636813, actual) // expected value calculated by hand. + } + + @Test + fun `WHEN converting ticks to nanos THEN the correct value is returned`() { + val actual = stat.convertTicksToNanos(166_636_813) + assertEquals(1_666_368_130_000_000.0, actual, 0.0) // expected value calculated by hand. + } + + @Test + fun `WHEN converting nanos to ticks THEN the correct value is returned`() { + val actual = stat.convertNanosToTicks(1_666_368_135_432_102) + assertEquals(166_636_813.5432102, actual, 0.0) // expected value calculated by hand. + } +} + +class StatTestImpl : Stat() { + override fun getStatText(pid: Int): String = STAT_CONTENTS + override val clockTicksPerSecond: Long get() = CLOCK_TICKS_PER_SECOND +} diff --git a/docs/metrics.md b/docs/metrics.md index 7b23baad606b..e95729c3ad3b 100644 --- a/docs/metrics.md +++ b/docs/metrics.md @@ -12,6 +12,7 @@ This means you might have to go searching through the dependency tree to get a f - [events](#events) - [installation](#installation) - [metrics](#metrics) + - [startup-timeline](#startup-timeline) ## activation @@ -242,6 +243,20 @@ The following metrics are added to the ping: | search.default_engine.name |[string](https://mozilla.github.io/glean/book/user/metrics/string.html) |If the search engine is pre-loaded with Fenix this value will be the search engine name. If it's a custom search engine (defined: https://github.com/mozilla-mobile/fenix/issues/1607) the value will be "custom" |[1](https://github.com/mozilla-mobile/fenix/pull/1606), [2](https://github.com/mozilla-mobile/fenix/pull/5216)||2020-09-01 | | search.default_engine.submission_url |[string](https://mozilla.github.io/glean/book/user/metrics/string.html) |If the search engine is pre-loaded with Fenix this value will be he base URL we use to build the search query for the search engine. For example: https://mysearchengine.com/?query=%s. If it's a custom search engine (defined: https://github.com/mozilla-mobile/fenix/issues/1607) the value will be "custom" |[1](https://github.com/mozilla-mobile/fenix/pull/1606), [2](https://github.com/mozilla-mobile/fenix/pull/5216)||2020-09-01 | +## startup-timeline + +This ping is intended to provide an understanding of startup performance. +The ping is intended to be captured by performance testing automation to report results there, in addition to user telemetry. We place these metrics into their own ping in order to isolate them and make this process easier. + + +The following metrics are added to the ping: + +| Name | Type | Description | Data reviews | Extras | Expiration | +| --- | --- | --- | --- | --- | --- | +| startup.timeline.clock_ticks_per_second |[counter](https://mozilla.github.io/glean/book/user/metrics/counter.html) |The number of clock tick time units that occur in one second on this particular device. This value is expected to be used in conjunction with the `framework_start` metric. |[1](https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626)||2020-07-15 | +| startup.timeline.framework_start |[timespan](https://mozilla.github.io/glean/book/user/metrics/timespan.html) |The duration the Android framework takes to start before letting us run code in `*Application.init`. This is calculated from `appInitTimestamp - processStartTimestamp`. `processStartTimestamp` is derived from the clock tick time unit, which is expected to be less granular than nanoseconds. Therefore, we convert and round our timestamps to clock ticks before computing the difference and convert back to nanoseconds to report. For debugging purposes, `clock_ticks_per_second`, which may vary between devices, is also reported as a metric. |[1](https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626)||2020-07-15 | +| startup.timeline.framework_start_error |[boolean](https://mozilla.github.io/glean/book/user/metrics/boolean.html) |An error when attempting to record `framework_start` - the application init timestamp returned a negative value - which is likely indicative of a bug in the implementation. |[1](https://github.com/mozilla-mobile/fenix/pull/9788#pullrequestreview-394228626)||2020-07-15 | +