diff --git a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt index 7e40e24aa5..03db2e676d 100644 --- a/app/src/main/java/org/mozilla/fenix/FenixApplication.kt +++ b/app/src/main/java/org/mozilla/fenix/FenixApplication.kt @@ -29,6 +29,7 @@ import mozilla.components.lib.crash.CrashReporter import mozilla.components.service.glean.Glean import mozilla.components.service.glean.config.Configuration import mozilla.components.service.glean.net.ConceptFetchHttpUploader +import mozilla.components.support.base.facts.register import mozilla.components.support.base.log.Log import mozilla.components.support.base.log.logger.Logger import mozilla.components.support.ktx.android.content.isMainProcess @@ -41,6 +42,7 @@ import mozilla.components.support.webextensions.WebExtensionSupport import org.mozilla.fenix.components.Components import org.mozilla.fenix.components.metrics.MetricServiceType import org.mozilla.fenix.ext.settings +import org.mozilla.fenix.perf.ProfilerMarkerFactProcessor import org.mozilla.fenix.perf.StartupTimeline import org.mozilla.fenix.perf.StorageStatsMetrics import org.mozilla.fenix.perf.runBlockingIncrement @@ -118,6 +120,8 @@ open class FenixApplication : LocaleAwareApplication(), Provider { @CallSuper open fun setupInMainProcessOnly() { + ProfilerMarkerFactProcessor.create { components.core.engine.profiler }.register() + run { // Attention: Do not invoke any code from a-s in this scope. val megazordSetup = setupMegazord() diff --git a/app/src/main/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessor.kt b/app/src/main/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessor.kt new file mode 100644 index 0000000000..2e493cb2b0 --- /dev/null +++ b/app/src/main/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessor.kt @@ -0,0 +1,82 @@ +/* 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.Handler +import android.os.Looper +import androidx.annotation.VisibleForTesting +import androidx.annotation.VisibleForTesting.PRIVATE +import mozilla.components.concept.base.profiler.Profiler +import mozilla.components.support.base.facts.Action +import mozilla.components.support.base.facts.Fact +import mozilla.components.support.base.facts.FactProcessor + +/** + * A fact processor that adds Gecko profiler markers for [Fact]s matching a specific format. + * We look for the following format: + * ``` + * Fact( + * action = Action.IMPLEMENTATION_DETAIL + * item = + * ) + * ``` + * + * This allows us to add profiler markers from android-components code. Using the Fact API for this + * purpose, rather than calling [Profiler.addMarker] directly inside components, has trade-offs. Its + * downsides are that it is less explicit and tooling does not work as well on it. However, we felt + * it was worthwhile because: + * + * 1. we don't know what profiler markers are useful so we want to be able to iterate quickly. + * Adding dependencies on the Profiler and landing these changes across two repos hinders that + * 2. we want to instrument the code as close to specific method calls as possible (e.g. + * GeckoSession.loadUrl) but it's not always easy to do so (e.g. in the previous example, passing a + * Profiler reference to GeckoEngineSession is difficult because GES is not a global dependency) + * 3. we can only add Profiler markers from the main thread so adding markers will become more + * difficult if we have to understand the threading needs of each Profiler call site + * + * An additional benefit with having this infrastructure is that it's easy to add Profiler markers + * for local debugging. + * + * That being said, if we find a location where it would be valuable to have a long term Profiler + * marker, we should consider instrumenting it via the [Profiler] API. + */ +class ProfilerMarkerFactProcessor @VisibleForTesting(otherwise = PRIVATE) constructor( + // We use a provider to defer accessing the profiler until we need it, because the property is a + // child of the engine property and we don't want to initialize it earlier than we intend to. + private val profilerProvider: () -> Profiler?, + private val mainHandler: Handler = Handler(Looper.getMainLooper()), + private val getMyLooper: () -> Looper? = { Looper.myLooper() } +) : FactProcessor { + + override fun process(fact: Fact) { + if (fact.action != Action.IMPLEMENTATION_DETAIL) { + return + } + + val markerName = fact.item + + // Java profiler markers can only be added from the main thread so, for now, we push all + // markers to the the main thread (which also groups all the markers together, + // making it easier to read). + val profiler = profilerProvider() + if (getMyLooper() == mainHandler.looper) { + profiler?.addMarker(markerName) + } else { + // To reduce the performance burden, we could early return if the profiler isn't active. + // However, this would change the performance characteristics from when the profiler is + // active and when it's inactive so we always post instead. + val now = profiler?.getProfilerTime() + mainHandler.post { + // We set now to both start and end time because we want a marker of without duration + // and if end is omitted, the duration is created implicitly. + profiler?.addMarker(markerName, now, now, null) + } + } + } + + companion object { + fun create(profilerProvider: () -> Profiler?) = ProfilerMarkerFactProcessor(profilerProvider) + } +} diff --git a/app/src/test/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessorTest.kt b/app/src/test/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessorTest.kt new file mode 100644 index 0000000000..d0763e75ae --- /dev/null +++ b/app/src/test/java/org/mozilla/fenix/perf/ProfilerMarkerFactProcessorTest.kt @@ -0,0 +1,89 @@ +/* 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.Handler +import android.os.Looper +import io.mockk.Called +import io.mockk.MockKAnnotations +import io.mockk.every +import io.mockk.impl.annotations.RelaxedMockK +import io.mockk.mockk +import io.mockk.slot +import io.mockk.verify +import mozilla.components.concept.base.profiler.Profiler +import mozilla.components.support.base.Component +import mozilla.components.support.base.facts.Action +import mozilla.components.support.base.facts.Fact +import org.junit.Before +import org.junit.Test + +class ProfilerMarkerFactProcessorTest { + + @RelaxedMockK lateinit var profiler: Profiler + @RelaxedMockK lateinit var mainHandler: Handler + lateinit var processor: ProfilerMarkerFactProcessor + + var myLooper: Looper? = null + + @Before + fun setUp() { + MockKAnnotations.init(this) + myLooper = null + processor = ProfilerMarkerFactProcessor({ profiler }, mainHandler, { myLooper }) + } + + @Test + fun `GIVEN we are on the main thread WHEN a fact with an implementation detail action is received THEN a profiler marker is added now`() { + myLooper = mainHandler.looper // main thread + + val fact = newFact(Action.IMPLEMENTATION_DETAIL) + processor.process(fact) + + verify { profiler.addMarker(fact.item) } + } + + @Test + fun `GIVEN we are not on the main thread WHEN a fact with an implementation detail action is received THEN adding the marker is posted to the main thread`() { + myLooper = mockk() // off main thread + val mainThreadPostedSlot = slot() + every { profiler.getProfilerTime() } returns 100.0 + + val fact = newFact(Action.IMPLEMENTATION_DETAIL) + processor.process(fact) + + verify { mainHandler.post(capture(mainThreadPostedSlot)) } + verifyProfilerAddMarkerWasNotCalled() + + mainThreadPostedSlot.captured.run() // call the captured function posted to the main thread. + verify { profiler.addMarker(fact.item, 100.0, 100.0, null) } + } + + @Test + fun `WHEN a fact with a non-implementation detail action is received THEN no profiler marker is added`() { + val fact = newFact(Action.CANCEL) + processor.process(fact) + verify { profiler wasNot Called } + } + + private fun verifyProfilerAddMarkerWasNotCalled() { + verify(exactly = 0) { + profiler.addMarker(any()) + profiler.addMarker(any(), any() as Double?) + profiler.addMarker(any(), any() as String?) + profiler.addMarker(any(), any(), any()) + profiler.addMarker(any(), any(), any(), any()) + } + } +} + +private fun newFact( + action: Action, + item: String = "itemName" +) = Fact( + Component.BROWSER_SESSION, + action, + item +)