blallo
/
fenix
1
0
Fork 0
Code Releases Activity

For #8803: add StartupFrameworkStartMeasurement. 

This class controls the central logic around the metrics we want to
record.
master
Michael Comella 2020-04-07 14:41:12 -07:00 committed by Michael Comella
parent 7f618a6a7c
commit dbf733d70a
2 changed files with 203 additions and 0 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

86
app/src/main/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurement.kt 100644
View File

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

117
app/src/test/java/org/mozilla/fenix/perf/StartupFrameworkStartMeasurementTest.kt 100644
View File

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