diff --git a/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitter.kt b/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitter.kt index 55be74e8f..f357458de 100644 --- a/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitter.kt +++ b/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitter.kt @@ -48,13 +48,13 @@ internal class AppStartupTraceEmitter( init { val timestampAtDeviceStart = nowMs() - clock.nanoTime().nanosToMillis() - processCreateRequestedMs = if (versionChecker.isAtLeast(VERSION_CODES.N)) { - timestampAtDeviceStart + Process.getStartElapsedRealtime() + processCreateRequestedMs = if (versionChecker.isAtLeast(VERSION_CODES.TIRAMISU)) { + timestampAtDeviceStart + Process.getStartRequestedElapsedRealtime() } else { null } - processCreatedMs = if (versionChecker.isAtLeast(VERSION_CODES.TIRAMISU)) { - timestampAtDeviceStart + Process.getStartRequestedElapsedRealtime() + processCreatedMs = if (versionChecker.isAtLeast(VERSION_CODES.N)) { + timestampAtDeviceStart + Process.getStartElapsedRealtime() } else { null } @@ -134,6 +134,7 @@ internal class AppStartupTraceEmitter( } } + @Suppress("CyclomaticComplexMethod", "ComplexMethod") private fun recordStartup() { val startupService = startupServiceProvider() ?: return val sdkInitStartMs = startupService.getSdkInitStartMs() diff --git a/embrace-android-sdk/src/test/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitterTest.kt b/embrace-android-sdk/src/test/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitterTest.kt index b04a120c2..dd4fad66d 100644 --- a/embrace-android-sdk/src/test/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitterTest.kt +++ b/embrace-android-sdk/src/test/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitterTest.kt @@ -4,6 +4,7 @@ import android.os.Build import androidx.test.ext.junit.runners.AndroidJUnit4 import io.embrace.android.embracesdk.concurrency.BlockableExecutorService import io.embrace.android.embracesdk.fakes.FakeClock +import io.embrace.android.embracesdk.fakes.FakeClock.Companion.DEFAULT_FAKE_CURRENT_TIME import io.embrace.android.embracesdk.fakes.FakeLoggerAction import io.embrace.android.embracesdk.fakes.injection.FakeInitModule import io.embrace.android.embracesdk.internal.clock.nanosToMillis @@ -18,6 +19,14 @@ import org.junit.Test import org.junit.runner.RunWith import org.robolectric.annotation.Config +/** + * The various combinations of OS capabilities mean we have to test the following Android versions: + * + * - 14+: cold start trace from process create to render, process requested time available + * - 10 to 13: cold start trace from process create to render, process requested time NOT available + * - 7 to 9: cold start trace from process create to activity resume, process requested time NOT available + * - 5 to 6.0.1: cold start trace application init if available (sdk init if not) to activity resume + */ @RunWith(AndroidJUnit4::class) internal class AppStartupTraceEmitterTest { private var startupService: StartupService? = null @@ -66,8 +75,129 @@ internal class AppStartupTraceEmitterTest { @Config(sdk = [Build.VERSION_CODES.TIRAMISU]) @Test fun `verify cold start trace with every event triggered in T`() { + verifyColdStartWithRender() + } + + @Config(sdk = [Build.VERSION_CODES.TIRAMISU]) + @Test + fun `verify cold start trace without application init start and end triggered in T`() { + verifyColdStartWithRenderWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.TIRAMISU]) + @Test + fun `verify warm start trace without application init start and end triggered in T`() { + verifyWarmStartWithRenderWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.S]) + @Test + fun `no crashes if startup service not available in S`() { + startupService = null + appStartupTraceEmitter.firstFrameRendered() + assertEquals(1, loggerAction.msgQueue.size) + } + + @Config(sdk = [Build.VERSION_CODES.S]) + @Test + fun `verify cold start trace with every event triggered in S`() { + verifyColdStartWithRender() + } + + @Config(sdk = [Build.VERSION_CODES.S]) + @Test + fun `verify cold start trace without application init start and end triggered in S`() { + verifyColdStartWithRenderWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.S]) + @Test + fun `verify warm start trace without application init start and end triggered in S`() { + verifyWarmStartWithRenderWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.P]) + @Test + fun `no crashes if startup service not available in P`() { + startupService = null + appStartupTraceEmitter.startupActivityResumed() + assertEquals(1, loggerAction.msgQueue.size) + } + + @Config(sdk = [Build.VERSION_CODES.P]) + @Test + fun `verify cold start trace with every event triggered in P`() { + verifyColdStartWithResume() + } + + @Config(sdk = [Build.VERSION_CODES.P]) + @Test + fun `verify cold start trace without application init start and end triggered in P`() { + verifyColdStartWithResumeWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.P]) + @Test + fun `verify warm start trace without application init start and end triggered in O`() { + verifyWarmStartWithResumeWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.M]) + @Test + fun `no crashes if startup service not available in M`() { + startupService = null + appStartupTraceEmitter.startupActivityResumed() + assertEquals(1, loggerAction.msgQueue.size) + } + + @Config(sdk = [Build.VERSION_CODES.M]) + @Test + fun `verify cold start trace with every event triggered in M`() { + verifyColdStartWithResume(trackProcessStart = false) + } + + @Config(sdk = [Build.VERSION_CODES.M]) + @Test + fun `verify cold start trace without application init start and end triggered in M`() { + verifyColdStartWithResumeWithoutAppInitEvents(trackProcessStart = false) + } + + @Config(sdk = [Build.VERSION_CODES.M]) + @Test + fun `verify warm start trace without application init start and end triggered in M`() { + verifyWarmStartWithResumeWithoutAppInitEvents() + } + + @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) + @Test + fun `no crashes if startup service not available in L`() { + startupService = null + appStartupTraceEmitter.startupActivityResumed() + assertEquals(1, loggerAction.msgQueue.size) + } + + @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) + @Test + fun `verify cold start trace with every event triggered in L`() { + verifyColdStartWithResume(trackProcessStart = false) + } + + @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) + @Test + fun `verify cold start trace without application init start and end triggered in L`() { + verifyColdStartWithResumeWithoutAppInitEvents(trackProcessStart = false) + } + + @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) + @Test + fun `verify warm start trace without application init start and end triggered in L`() { + verifyWarmStartWithResumeWithoutAppInitEvents() + } + + private fun verifyColdStartWithRender() { clock.tick(100L) appStartupTraceEmitter.applicationInitStart() + clock.tick(15L) val sdkInitStart = clock.now() clock.tick(30L) val sdkInitEnd = clock.now() @@ -97,11 +227,11 @@ internal class AppStartupTraceEmitterTest { val firstRender = checkNotNull(spanMap["emb-first-frame-render"]) with(trace) { - assertEquals(FakeClock.DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) + assertEquals(DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) } with(processInit) { - assertEquals(FakeClock.DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) + assertEquals(DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) assertEquals(applicationInitEnd, endTimeNanos.nanosToMillis()) } with(embraceInit) { @@ -124,9 +254,7 @@ internal class AppStartupTraceEmitterTest { assertEquals(0, loggerAction.msgQueue.size) } - @Config(sdk = [Build.VERSION_CODES.TIRAMISU]) - @Test - fun `verify cold start trace without application init start and end triggered in T`() { + private fun verifyColdStartWithRenderWithoutAppInitEvents() { clock.tick(100L) val sdkInitStart = clock.now() clock.tick(30L) @@ -153,7 +281,7 @@ internal class AppStartupTraceEmitterTest { val firstRender = checkNotNull(spanMap["emb-first-frame-render"]) with(trace) { - assertEquals(FakeClock.DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) + assertEquals(DEFAULT_FAKE_CURRENT_TIME, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) } with(embraceInit) { @@ -176,15 +304,19 @@ internal class AppStartupTraceEmitterTest { assertEquals(0, loggerAction.msgQueue.size) } - @Config(sdk = [Build.VERSION_CODES.TIRAMISU]) - @Test - fun `verify warm start trace without application init start and end triggered in T`() { + private fun verifyColdStartWithResume(trackProcessStart: Boolean = true) { clock.tick(100L) + appStartupTraceEmitter.applicationInitStart() + val applicationInitStart = clock.now() + clock.tick(10L) val sdkInitStart = clock.now() clock.tick(30L) val sdkInitEnd = clock.now() + clock.tick(400L) + appStartupTraceEmitter.applicationInitEnd() + val applicationInitEnd = clock.now() + clock.tick(50L) checkNotNull(startupService).setSdkStartupInfo(sdkInitStart, sdkInitEnd) - clock.tick(60001L) appStartupTraceEmitter.startupActivityInitStart() val startupActivityStart = clock.now() clock.tick(180L) @@ -192,27 +324,44 @@ internal class AppStartupTraceEmitterTest { val startupActivityEnd = clock.now() clock.tick(15L) appStartupTraceEmitter.startupActivityResumed() - clock.tick(199L) - appStartupTraceEmitter.firstFrameRendered() val traceEnd = clock.now() - assertEquals(4, spanSink.completedSpans().size) + assertEquals(7, spanSink.completedSpans().size) val spanMap = spanSink.completedSpans().associateBy { it.name } - val trace = checkNotNull(spanMap["emb-warm-time-to-initial-display"]) + val trace = checkNotNull(spanMap["emb-cold-time-to-initial-display"]) + val processInit = checkNotNull(spanMap["emb-process-init"]) + val embraceInit = checkNotNull(spanMap["emb-embrace-init"]) + val activityInitDelay = checkNotNull(spanMap["emb-activity-init-gap"]) val activityCreate = checkNotNull(spanMap["emb-activity-create"]) - val firstRender = checkNotNull(spanMap["emb-first-frame-render"]) + val activityResume = checkNotNull(spanMap["emb-activity-resume"]) + + val traceStartMs = if (trackProcessStart) { + DEFAULT_FAKE_CURRENT_TIME + } else { + applicationInitStart + } with(trace) { - assertEquals(startupActivityStart, startTimeNanos.nanosToMillis()) + assertEquals(traceStartMs, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) - assertEquals("60001", attributes["emb.activity-init-gap-ms"]) - assertEquals("30", attributes["emb.embrace-init-duration-ms"]) + } + with(processInit) { + assertEquals(traceStartMs, startTimeNanos.nanosToMillis()) + assertEquals(applicationInitEnd, endTimeNanos.nanosToMillis()) + } + with(embraceInit) { + assertEquals(sdkInitStart, startTimeNanos.nanosToMillis()) + assertEquals(sdkInitEnd, endTimeNanos.nanosToMillis()) + } + with(activityInitDelay) { + assertEquals(applicationInitEnd, startTimeNanos.nanosToMillis()) + assertEquals(startupActivityStart, endTimeNanos.nanosToMillis()) } with(activityCreate) { assertEquals(startupActivityStart, startTimeNanos.nanosToMillis()) assertEquals(startupActivityEnd, endTimeNanos.nanosToMillis()) } - with(firstRender) { + with(activityResume) { assertEquals(startupActivityEnd, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) } @@ -220,28 +369,12 @@ internal class AppStartupTraceEmitterTest { assertEquals(0, loggerAction.msgQueue.size) } - @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) - @Test - fun `no crashes if startup service not available in L`() { - startupService = null - appStartupTraceEmitter.startupActivityResumed() - assertEquals(1, loggerAction.msgQueue.size) - } - - @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) - @Test - fun `verify cold start trace with every event triggered in L`() { + private fun verifyColdStartWithResumeWithoutAppInitEvents(trackProcessStart: Boolean = true) { clock.tick(100L) - appStartupTraceEmitter.applicationInitStart() - val applicationInitStart = clock.now() - clock.tick(10L) val sdkInitStart = clock.now() clock.tick(30L) val sdkInitEnd = clock.now() clock.tick(400L) - appStartupTraceEmitter.applicationInitEnd() - val applicationInitEnd = clock.now() - clock.tick(50L) checkNotNull(startupService).setSdkStartupInfo(sdkInitStart, sdkInitEnd) appStartupTraceEmitter.startupActivityInitStart() val startupActivityStart = clock.now() @@ -252,29 +385,30 @@ internal class AppStartupTraceEmitterTest { appStartupTraceEmitter.startupActivityResumed() val traceEnd = clock.now() - assertEquals(7, spanSink.completedSpans().size) + assertEquals(6, spanSink.completedSpans().size) val spanMap = spanSink.completedSpans().associateBy { it.name } val trace = checkNotNull(spanMap["emb-cold-time-to-initial-display"]) - val processInit = checkNotNull(spanMap["emb-process-init"]) val embraceInit = checkNotNull(spanMap["emb-embrace-init"]) val activityInitDelay = checkNotNull(spanMap["emb-activity-init-gap"]) val activityCreate = checkNotNull(spanMap["emb-activity-create"]) val activityResume = checkNotNull(spanMap["emb-activity-resume"]) + val traceStartMs = if (trackProcessStart) { + DEFAULT_FAKE_CURRENT_TIME + } else { + sdkInitStart + } + with(trace) { - assertEquals(applicationInitStart, startTimeNanos.nanosToMillis()) + assertEquals(traceStartMs, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) } - with(processInit) { - assertEquals(applicationInitStart, startTimeNanos.nanosToMillis()) - assertEquals(applicationInitEnd, endTimeNanos.nanosToMillis()) - } with(embraceInit) { assertEquals(sdkInitStart, startTimeNanos.nanosToMillis()) assertEquals(sdkInitEnd, endTimeNanos.nanosToMillis()) } with(activityInitDelay) { - assertEquals(applicationInitEnd, startTimeNanos.nanosToMillis()) + assertEquals(sdkInitEnd, startTimeNanos.nanosToMillis()) assertEquals(startupActivityStart, endTimeNanos.nanosToMillis()) } with(activityCreate) { @@ -289,15 +423,13 @@ internal class AppStartupTraceEmitterTest { assertEquals(0, loggerAction.msgQueue.size) } - @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) - @Test - fun `verify cold start trace without application init start and end triggered in L`() { + private fun verifyWarmStartWithRenderWithoutAppInitEvents() { clock.tick(100L) val sdkInitStart = clock.now() clock.tick(30L) val sdkInitEnd = clock.now() - clock.tick(400L) checkNotNull(startupService).setSdkStartupInfo(sdkInitStart, sdkInitEnd) + clock.tick(60001L) appStartupTraceEmitter.startupActivityInitStart() val startupActivityStart = clock.now() clock.tick(180L) @@ -305,33 +437,27 @@ internal class AppStartupTraceEmitterTest { val startupActivityEnd = clock.now() clock.tick(15L) appStartupTraceEmitter.startupActivityResumed() + clock.tick(199L) + appStartupTraceEmitter.firstFrameRendered() val traceEnd = clock.now() - assertEquals(6, spanSink.completedSpans().size) + assertEquals(4, spanSink.completedSpans().size) val spanMap = spanSink.completedSpans().associateBy { it.name } - val trace = checkNotNull(spanMap["emb-cold-time-to-initial-display"]) - val embraceInit = checkNotNull(spanMap["emb-embrace-init"]) - val activityInitDelay = checkNotNull(spanMap["emb-activity-init-gap"]) + val trace = checkNotNull(spanMap["emb-warm-time-to-initial-display"]) val activityCreate = checkNotNull(spanMap["emb-activity-create"]) - val activityResume = checkNotNull(spanMap["emb-activity-resume"]) + val firstRender = checkNotNull(spanMap["emb-first-frame-render"]) with(trace) { - assertEquals(sdkInitStart, startTimeNanos.nanosToMillis()) + assertEquals(startupActivityStart, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) - } - with(embraceInit) { - assertEquals(sdkInitStart, startTimeNanos.nanosToMillis()) - assertEquals(sdkInitEnd, endTimeNanos.nanosToMillis()) - } - with(activityInitDelay) { - assertEquals(sdkInitEnd, startTimeNanos.nanosToMillis()) - assertEquals(startupActivityStart, endTimeNanos.nanosToMillis()) + assertEquals("60001", attributes["emb.activity-init-gap-ms"]) + assertEquals("30", attributes["emb.embrace-init-duration-ms"]) } with(activityCreate) { assertEquals(startupActivityStart, startTimeNanos.nanosToMillis()) assertEquals(startupActivityEnd, endTimeNanos.nanosToMillis()) } - with(activityResume) { + with(firstRender) { assertEquals(startupActivityEnd, startTimeNanos.nanosToMillis()) assertEquals(traceEnd, endTimeNanos.nanosToMillis()) } @@ -339,9 +465,7 @@ internal class AppStartupTraceEmitterTest { assertEquals(0, loggerAction.msgQueue.size) } - @Config(sdk = [Build.VERSION_CODES.LOLLIPOP]) - @Test - fun `verify warm start trace without application init start and end triggered in L`() { + private fun verifyWarmStartWithResumeWithoutAppInitEvents() { clock.tick(100L) val sdkInitStart = clock.now() clock.tick(30L)