[fenix] For https://github.com/mozilla-mobile/fenix/issues/8803: add StartupFrameworkStartMeasurement.
This class controls the central logic around the metrics we want to record.pull/600/head
parent
162a93a190
commit
deafedeada
@ -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)
|
||||||
|
}
|
@ -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 }
|
||||||
|
}
|
||||||
|
}
|
Loading…
Reference in New Issue