diff --git a/CHANGELOG.md b/CHANGELOG.md index 7dd0136c30..cac7585958 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,12 @@ # Changelog +## Unreleased + +### Fixes + +- Check app start spans time and ignore background app starts ([#3550](https://github.com/getsentry/sentry-java/pull/3550)) + - This should eliminate long-lasting App Start transactions + ## 7.12.0 ### Features diff --git a/sentry-android-core/api/sentry-android-core.api b/sentry-android-core/api/sentry-android-core.api index 0e493f54a7..478a1ddd3c 100644 --- a/sentry-android-core/api/sentry-android-core.api +++ b/sentry-android-core/api/sentry-android-core.api @@ -427,7 +427,7 @@ public class io/sentry/android/core/performance/ActivityLifecycleTimeSpan : java public final fun getOnStart ()Lio/sentry/android/core/performance/TimeSpan; } -public class io/sentry/android/core/performance/AppStartMetrics { +public class io/sentry/android/core/performance/AppStartMetrics : io/sentry/android/core/performance/ActivityLifecycleCallbacksAdapter { public fun ()V public fun addActivityLifecycleTimeSpans (Lio/sentry/android/core/performance/ActivityLifecycleTimeSpan;)V public fun clear ()V @@ -443,10 +443,13 @@ public class io/sentry/android/core/performance/AppStartMetrics { public static fun getInstance ()Lio/sentry/android/core/performance/AppStartMetrics; public fun getSdkInitTimeSpan ()Lio/sentry/android/core/performance/TimeSpan; public fun isAppLaunchedInForeground ()Z + public fun onActivityCreated (Landroid/app/Activity;Landroid/os/Bundle;)V public static fun onApplicationCreate (Landroid/app/Application;)V public static fun onApplicationPostCreate (Landroid/app/Application;)V public static fun onContentProviderCreate (Landroid/content/ContentProvider;)V public static fun onContentProviderPostCreate (Landroid/content/ContentProvider;)V + public fun registerApplicationForegroundCheck (Landroid/app/Application;)V + public fun setAppLaunchedInForeground (Z)V public fun setAppStartProfiler (Lio/sentry/ITransactionProfiler;)V public fun setAppStartSamplingDecision (Lio/sentry/TracesSamplingDecision;)V public fun setAppStartType (Lio/sentry/android/core/performance/AppStartMetrics$AppStartType;)V diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index 205360b8f1..7556afb235 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -21,6 +21,7 @@ import io.sentry.NoOpTransaction; import io.sentry.SentryDate; import io.sentry.SentryLevel; +import io.sentry.SentryNanotimeDate; import io.sentry.SentryOptions; import io.sentry.SpanStatus; import io.sentry.TracesSamplingDecision; @@ -37,6 +38,7 @@ import java.io.Closeable; import java.io.IOException; import java.lang.ref.WeakReference; +import java.util.Date; import java.util.Map; import java.util.WeakHashMap; import java.util.concurrent.Future; @@ -75,7 +77,7 @@ public final class ActivityLifecycleIntegration private @Nullable ISpan appStartSpan; private final @NotNull WeakHashMap ttidSpanMap = new WeakHashMap<>(); private final @NotNull WeakHashMap ttfdSpanMap = new WeakHashMap<>(); - private @NotNull SentryDate lastPausedTime = AndroidDateUtils.getCurrentSentryDateTime(); + private @NotNull SentryDate lastPausedTime = new SentryNanotimeDate(new Date(0), 0); private final @NotNull Handler mainHandler = new Handler(Looper.getMainLooper()); private @Nullable Future ttfdAutoCloseFuture = null; @@ -627,6 +629,14 @@ WeakHashMap getTtfdSpanMap() { } private void setColdStart(final @Nullable Bundle savedInstanceState) { + // The very first activity start timestamp cannot be set to the class instantiation time, as it + // may happen before an activity is started (service, broadcast receiver, etc). So we set it + // here. + if (hub != null && lastPausedTime.nanoTimestamp() == 0) { + lastPausedTime = hub.getOptions().getDateProvider().now(); + } else if (lastPausedTime.nanoTimestamp() == 0) { + lastPausedTime = AndroidDateUtils.getCurrentSentryDateTime(); + } if (!firstActivityCreated) { // if Activity has savedInstanceState then its a warm start // https://developer.android.com/topic/performance/vitals/launch-time#warm diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/SentryAndroid.java b/sentry-android-core/src/main/java/io/sentry/android/core/SentryAndroid.java index d444d08cb0..0c1a74edb0 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/SentryAndroid.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/SentryAndroid.java @@ -1,6 +1,7 @@ package io.sentry.android.core; import android.annotation.SuppressLint; +import android.app.Application; import android.content.Context; import android.os.Process; import android.os.SystemClock; @@ -141,6 +142,10 @@ public static synchronized void init( appStartTimeSpan.setStartedAt(Process.getStartUptimeMillis()); } } + if (context.getApplicationContext() instanceof Application) { + appStartMetrics.registerApplicationForegroundCheck( + (Application) context.getApplicationContext()); + } final @NotNull TimeSpan sdkInitTimeSpan = appStartMetrics.getSdkInitTimeSpan(); if (sdkInitTimeSpan.hasNotStarted()) { sdkInitTimeSpan.setStartedAt(sdkInitMillis); diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/SentryPerformanceProvider.java b/sentry-android-core/src/main/java/io/sentry/android/core/SentryPerformanceProvider.java index 354448c4f2..2ad465f1e3 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/SentryPerformanceProvider.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/SentryPerformanceProvider.java @@ -201,6 +201,7 @@ private void onAppLaunched( final @NotNull TimeSpan appStartTimespan = appStartMetrics.getAppStartTimeSpan(); appStartTimespan.setStartedAt(Process.getStartUptimeMillis()); + appStartMetrics.registerApplicationForegroundCheck(app); final AtomicBoolean firstDrawDone = new AtomicBoolean(false); diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/performance/AppStartMetrics.java b/sentry-android-core/src/main/java/io/sentry/android/core/performance/AppStartMetrics.java index 5c29e95b63..a220f5eb4a 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/performance/AppStartMetrics.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/performance/AppStartMetrics.java @@ -1,10 +1,18 @@ package io.sentry.android.core.performance; +import android.app.Activity; import android.app.Application; import android.content.ContentProvider; +import android.os.Bundle; +import android.os.Handler; +import android.os.Looper; import android.os.SystemClock; +import androidx.annotation.NonNull; import androidx.annotation.Nullable; +import androidx.annotation.VisibleForTesting; import io.sentry.ITransactionProfiler; +import io.sentry.SentryDate; +import io.sentry.SentryNanotimeDate; import io.sentry.TracesSamplingDecision; import io.sentry.android.core.ContextUtils; import io.sentry.android.core.SentryAndroidOptions; @@ -13,6 +21,7 @@ import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.concurrent.TimeUnit; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.TestOnly; @@ -23,7 +32,7 @@ * transformed into SDK specific txn/span data structures. */ @ApiStatus.Internal -public class AppStartMetrics { +public class AppStartMetrics extends ActivityLifecycleCallbacksAdapter { public enum AppStartType { UNKNOWN, @@ -45,6 +54,9 @@ public enum AppStartType { private final @NotNull List activityLifecycles; private @Nullable ITransactionProfiler appStartProfiler = null; private @Nullable TracesSamplingDecision appStartSamplingDecision = null; + private @Nullable SentryDate onCreateTime = null; + private boolean appLaunchTooLong = false; + private boolean isCallbackRegistered = false; public static @NotNull AppStartMetrics getInstance() { @@ -65,6 +77,7 @@ public AppStartMetrics() { applicationOnCreate = new TimeSpan(); contentProviderOnCreates = new HashMap<>(); activityLifecycles = new ArrayList<>(); + appLaunchedInForeground = ContextUtils.isForegroundImportance(); } /** @@ -102,6 +115,11 @@ public boolean isAppLaunchedInForeground() { return appLaunchedInForeground; } + @VisibleForTesting + public void setAppLaunchedInForeground(final boolean appLaunchedInForeground) { + this.appLaunchedInForeground = appLaunchedInForeground; + } + /** * Provides all collected content provider onCreate time spans * @@ -137,12 +155,20 @@ public long getClassLoadedUptimeMs() { // Only started when sdk version is >= N final @NotNull TimeSpan appStartSpan = getAppStartTimeSpan(); if (appStartSpan.hasStarted()) { - return appStartSpan; + return validateAppStartSpan(appStartSpan); } } // fallback: use sdk init time span, as it will always have a start time set - return getSdkInitTimeSpan(); + return validateAppStartSpan(getSdkInitTimeSpan()); + } + + private @NotNull TimeSpan validateAppStartSpan(final @NotNull TimeSpan appStartSpan) { + // If the app launch took too long or it was launched in the background we return an empty span + if (appLaunchTooLong || !appLaunchedInForeground) { + return new TimeSpan(); + } + return appStartSpan; } @TestOnly @@ -158,6 +184,10 @@ public void clear() { } appStartProfiler = null; appStartSamplingDecision = null; + appLaunchTooLong = false; + appLaunchedInForeground = false; + onCreateTime = null; + isCallbackRegistered = false; } public @Nullable ITransactionProfiler getAppStartProfiler() { @@ -195,7 +225,55 @@ public static void onApplicationCreate(final @NotNull Application application) { final @NotNull AppStartMetrics instance = getInstance(); if (instance.applicationOnCreate.hasNotStarted()) { instance.applicationOnCreate.setStartedAt(now); - instance.appLaunchedInForeground = ContextUtils.isForegroundImportance(); + instance.registerApplicationForegroundCheck(application); + } + } + + /** + * Register a callback to check if an activity was started after the application was created + * + * @param application The application object to register the callback to + */ + public void registerApplicationForegroundCheck(final @NotNull Application application) { + if (isCallbackRegistered) { + return; + } + isCallbackRegistered = true; + appLaunchedInForeground = appLaunchedInForeground || ContextUtils.isForegroundImportance(); + application.registerActivityLifecycleCallbacks(instance); + new Handler(Looper.getMainLooper()) + .post( + () -> { + // if no activity has ever been created, app was launched in background + if (onCreateTime == null) { + appLaunchedInForeground = false; + } + application.unregisterActivityLifecycleCallbacks(instance); + // we stop the app start profiler, as it's useless and likely to timeout + if (appStartProfiler != null && appStartProfiler.isRunning()) { + appStartProfiler.close(); + appStartProfiler = null; + } + }); + } + + @Override + public void onActivityCreated(@NonNull Activity activity, @Nullable Bundle savedInstanceState) { + // An activity already called onCreate() + if (!appLaunchedInForeground || onCreateTime != null) { + return; + } + onCreateTime = new SentryNanotimeDate(); + + final long spanStartMillis = appStartSpan.getStartTimestampMs(); + final long spanEndMillis = + appStartSpan.hasStopped() + ? appStartSpan.getProjectedStopTimestampMs() + : System.currentTimeMillis(); + final long durationMillis = spanEndMillis - spanStartMillis; + // If the app was launched more than 1 minute ago, it's likely wrong + if (durationMillis > TimeUnit.MINUTES.toMillis(1)) { + appLaunchTooLong = true; } } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index f936b6251c..b355075ff1 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt @@ -54,6 +54,7 @@ import org.robolectric.shadow.api.Shadow import org.robolectric.shadows.ShadowActivityManager import java.util.Date import java.util.concurrent.Future +import java.util.concurrent.TimeUnit import kotlin.test.AfterTest import kotlin.test.BeforeTest import kotlin.test.Test @@ -94,6 +95,7 @@ class ActivityLifecycleIntegrationTest { whenever(hub.options).thenReturn(options) + AppStartMetrics.getInstance().isAppLaunchedInForeground = true // We let the ActivityLifecycleIntegration create the proper transaction here val optionCaptor = argumentCaptor() val contextCaptor = argumentCaptor() @@ -709,15 +711,19 @@ class ActivityLifecycleIntegrationTest { sut.register(fixture.hub, fixture.options) val date = SentryNanotimeDate(Date(1), 0) + val date2 = SentryNanotimeDate(Date(2), 2) setAppStartTime(date) val activity = mock() + // The activity onCreate date will be ignored + fixture.options.dateProvider = SentryDateProvider { date2 } sut.onActivityCreated(activity, fixture.bundle) verify(fixture.hub).startTransaction( any(), check { assertEquals(date.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) + assertNotEquals(date2.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) assertFalse(it.isAppStartTransaction) } ) @@ -756,6 +762,30 @@ class ActivityLifecycleIntegrationTest { ) } + @Test + fun `When firstActivityCreated is true and no app start time is set, default to onActivityCreated time`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + // usually set by SentryPerformanceProvider + val date = SentryNanotimeDate(Date(1), 0) + val date2 = SentryNanotimeDate(Date(2), 2) + + val activity = mock() + // Activity onCreate date will be used + fixture.options.dateProvider = SentryDateProvider { date2 } + sut.onActivityCreated(activity, fixture.bundle) + + verify(fixture.hub).startTransaction( + any(), + check { + assertEquals(date2.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) + assertNotEquals(date.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) + } + ) + } + @Test fun `Create and finish app start span immediately in case SDK init is deferred`() { val sut = fixture.getSut(importance = RunningAppProcessInfo.IMPORTANCE_FOREGROUND) @@ -940,6 +970,46 @@ class ActivityLifecycleIntegrationTest { assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) } + @Test + fun `When firstActivityCreated is true and app started more than 1 minute ago, app start spans are dropped`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + val date = SentryNanotimeDate(Date(1), 0) + val duration = TimeUnit.MINUTES.toMillis(1) + 2 + val durationNanos = TimeUnit.MILLISECONDS.toNanos(duration) + val stopDate = SentryNanotimeDate(Date(duration), durationNanos) + setAppStartTime(date, stopDate) + + val activity = mock() + sut.onActivityCreated(activity, null) + + val appStartSpan = fixture.transaction.children.firstOrNull { + it.description == "Cold Start" + } + assertNull(appStartSpan) + } + + @Test + fun `When firstActivityCreated is true and app started in background, app start spans are dropped`() { + val sut = fixture.getSut() + AppStartMetrics.getInstance().isAppLaunchedInForeground = false + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + val date = SentryNanotimeDate(Date(1), 0) + setAppStartTime(date) + + val activity = mock() + sut.onActivityCreated(activity, null) + + val appStartSpan = fixture.transaction.children.firstOrNull { + it.description == "Cold Start" + } + assertNull(appStartSpan) + } + @Test fun `When firstActivityCreated is false, start transaction but not with given appStartTime`() { val sut = fixture.getSut() @@ -1412,18 +1482,22 @@ class ActivityLifecycleIntegrationTest { shadowOf(Looper.getMainLooper()).idle() } - private fun setAppStartTime(date: SentryDate = SentryNanotimeDate(Date(1), 0)) { + private fun setAppStartTime(date: SentryDate = SentryNanotimeDate(Date(1), 0), stopDate: SentryDate? = null) { // set by SentryPerformanceProvider so forcing it here val sdkAppStartTimeSpan = AppStartMetrics.getInstance().sdkInitTimeSpan val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan val millis = DateUtils.nanosToMillis(date.nanoTimestamp().toDouble()).toLong() + val stopMillis = DateUtils.nanosToMillis(stopDate?.nanoTimestamp()?.toDouble() ?: 0.0).toLong() sdkAppStartTimeSpan.setStartedAt(millis) sdkAppStartTimeSpan.setStartUnixTimeMs(millis) - sdkAppStartTimeSpan.setStoppedAt(0) + sdkAppStartTimeSpan.setStoppedAt(stopMillis) appStartTimeSpan.setStartedAt(millis) appStartTimeSpan.setStartUnixTimeMs(millis) - appStartTimeSpan.setStoppedAt(0) + appStartTimeSpan.setStoppedAt(stopMillis) + if (stopDate != null) { + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + } } } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt index 4283326677..23ab5a3bc8 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt @@ -18,12 +18,14 @@ import io.sentry.android.core.performance.ActivityLifecycleTimeSpan import io.sentry.android.core.performance.AppStartMetrics import io.sentry.android.core.performance.AppStartMetrics.AppStartType import io.sentry.protocol.MeasurementValue +import io.sentry.protocol.SentryId import io.sentry.protocol.SentrySpan import io.sentry.protocol.SentryTransaction import org.junit.runner.RunWith import org.mockito.kotlin.any import org.mockito.kotlin.mock import org.mockito.kotlin.whenever +import java.util.concurrent.TimeUnit import kotlin.test.BeforeTest import kotlin.test.Test import kotlin.test.assertEquals @@ -46,6 +48,7 @@ class PerformanceAndroidEventProcessorTest { tracesSampleRate: Double? = 1.0, enablePerformanceV2: Boolean = false ): PerformanceAndroidEventProcessor { + AppStartMetrics.getInstance().isAppLaunchedInForeground = true options.tracesSampleRate = tracesSampleRate options.isEnablePerformanceV2 = enablePerformanceV2 whenever(hub.options).thenReturn(options) @@ -56,6 +59,24 @@ class PerformanceAndroidEventProcessorTest { private val fixture = Fixture() + private fun createAppStartSpan(traceId: SentryId) = SentrySpan( + 0.0, + 1.0, + traceId, + SpanId(), + null, + APP_START_COLD, + "App Start", + SpanStatus.OK, + null, + emptyMap(), + emptyMap(), + null, + null + ).also { + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + } + @BeforeTest fun `reset instance`() { AppStartMetrics.getInstance().clear() @@ -233,21 +254,7 @@ class PerformanceAndroidEventProcessorTest { var tr = SentryTransaction(tracer) // and it contains an app.start.cold span - val appStartSpan = SentrySpan( - 0.0, - 1.0, - tr.contexts.trace!!.traceId, - SpanId(), - null, - APP_START_COLD, - "App Start", - SpanStatus.OK, - null, - emptyMap(), - emptyMap(), - null, - null - ) + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) // then the app start metrics should be attached @@ -285,6 +292,110 @@ class PerformanceAndroidEventProcessorTest { ) } + @Test + fun `when app launched from background, app start spans are dropped`() { + // given some app start metrics + val appStartMetrics = AppStartMetrics.getInstance() + appStartMetrics.appStartType = AppStartType.COLD + appStartMetrics.appStartTimeSpan.setStartedAt(123) + appStartMetrics.appStartTimeSpan.setStoppedAt(456) + + val contentProvider = mock() + AppStartMetrics.onContentProviderCreate(contentProvider) + AppStartMetrics.onContentProviderPostCreate(contentProvider) + + appStartMetrics.applicationOnCreateTimeSpan.apply { + setStartedAt(10) + setStoppedAt(42) + } + + val activityTimeSpan = ActivityLifecycleTimeSpan() + activityTimeSpan.onCreate.description = "MainActivity.onCreate" + activityTimeSpan.onStart.description = "MainActivity.onStart" + + activityTimeSpan.onCreate.setStartedAt(200) + activityTimeSpan.onStart.setStartedAt(220) + activityTimeSpan.onStart.setStoppedAt(240) + activityTimeSpan.onCreate.setStoppedAt(260) + appStartMetrics.addActivityLifecycleTimeSpans(activityTimeSpan) + + // when an activity transaction is created + val sut = fixture.getSut(enablePerformanceV2 = true) + val context = TransactionContext("Activity", UI_LOAD_OP) + val tracer = SentryTracer(context, fixture.hub) + var tr = SentryTransaction(tracer) + + // and it contains an app.start.cold span + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) + tr.spans.add(appStartSpan) + + // but app is launched in background + AppStartMetrics.getInstance().isAppLaunchedInForeground = false + + // then the app start metrics are not attached + tr = sut.process(tr, Hint()) + + assertFalse( + tr.spans.any { + "process.load" == it.op || + "contentprovider.load" == it.op || + "application.load" == it.op || + "activity.load" == it.op + } + ) + } + + @Test + fun `when app start takes more than 1 minute, app start spans are dropped`() { + // given some app start metrics + val appStartMetrics = AppStartMetrics.getInstance() + appStartMetrics.appStartType = AppStartType.COLD + appStartMetrics.appStartTimeSpan.setStartedAt(123) + // and app start takes more than 1 minute + appStartMetrics.appStartTimeSpan.setStoppedAt(TimeUnit.MINUTES.toMillis(1) + 124) + + val contentProvider = mock() + AppStartMetrics.onContentProviderCreate(contentProvider) + AppStartMetrics.onContentProviderPostCreate(contentProvider) + + appStartMetrics.applicationOnCreateTimeSpan.apply { + setStartedAt(10) + setStoppedAt(42) + } + + val activityTimeSpan = ActivityLifecycleTimeSpan() + activityTimeSpan.onCreate.description = "MainActivity.onCreate" + activityTimeSpan.onStart.description = "MainActivity.onStart" + + activityTimeSpan.onCreate.setStartedAt(200) + activityTimeSpan.onStart.setStartedAt(220) + activityTimeSpan.onStart.setStoppedAt(240) + activityTimeSpan.onCreate.setStoppedAt(260) + appStartMetrics.addActivityLifecycleTimeSpans(activityTimeSpan) + + // when an activity transaction is created + val sut = fixture.getSut(enablePerformanceV2 = true) + val context = TransactionContext("Activity", UI_LOAD_OP) + val tracer = SentryTracer(context, fixture.hub) + var tr = SentryTransaction(tracer) + + // and it contains an app.start.cold span + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) + tr.spans.add(appStartSpan) + + // then the app start metrics are not attached + tr = sut.process(tr, Hint()) + + assertFalse( + tr.spans.any { + "process.load" == it.op || + "contentprovider.load" == it.op || + "application.load" == it.op || + "activity.load" == it.op + } + ) + } + @Test fun `does not add app start metrics to app start txn when it is not a cold start`() { // given some WARM app start metrics @@ -330,21 +441,7 @@ class PerformanceAndroidEventProcessorTest { val context = TransactionContext("Activity", UI_LOAD_OP) val tracer = SentryTracer(context, fixture.hub) var tr = SentryTransaction(tracer) - val appStartSpan = SentrySpan( - 0.0, - 1.0, - tr.contexts.trace!!.traceId, - SpanId(), - null, - APP_START_COLD, - "App Start", - SpanStatus.OK, - null, - emptyMap(), - emptyMap(), - null, - null - ) + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) // then the app start metrics should not be attached @@ -381,21 +478,7 @@ class PerformanceAndroidEventProcessorTest { val context = TransactionContext("Activity", UI_LOAD_OP) val tracer = SentryTracer(context, fixture.hub) var tr = SentryTransaction(tracer) - val appStartSpan = SentrySpan( - 0.0, - 1.0, - tr.contexts.trace!!.traceId, - SpanId(), - null, - APP_START_COLD, - "App Start", - SpanStatus.OK, - null, - emptyMap(), - emptyMap(), - null, - null - ) + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) // when the processor attaches the app start spans @@ -428,21 +511,7 @@ class PerformanceAndroidEventProcessorTest { val context = TransactionContext("Activity", UI_LOAD_OP) val tracer = SentryTracer(context, fixture.hub) var tr = SentryTransaction(tracer) - val appStartSpan = SentrySpan( - 0.0, - 1.0, - tr.contexts.trace!!.traceId, - SpanId(), - null, - APP_START_COLD, - "App Start", - SpanStatus.OK, - null, - emptyMap(), - emptyMap(), - null, - null - ) + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) // when the processor attaches the app start spans @@ -493,21 +562,7 @@ class PerformanceAndroidEventProcessorTest { val tracer = SentryTracer(context, fixture.hub) var tr = SentryTransaction(tracer) - val appStartSpan = SentrySpan( - 0.0, - 1.0, - tr.contexts.trace!!.traceId, - SpanId(), - null, - APP_START_COLD, - "App Start", - SpanStatus.OK, - null, - emptyMap(), - emptyMap(), - null, - null - ) + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) // when the processor attaches the app start spans diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt index cf00173513..aa721bdb41 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt @@ -348,6 +348,15 @@ class SentryAndroidTest { } } + @Test + fun `When initializing Sentry a callback is added to application by appStartMetrics`() { + val mockContext = ContextUtilsTestHelper.createMockContext(true) + SentryAndroid.init(mockContext) { + it.dsn = "https://key@sentry.io/123" + } + verify(mockContext.applicationContext as Application).registerActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + } + private fun initSentryWithForegroundImportance( inForeground: Boolean, optionsConfig: (SentryAndroidOptions) -> Unit = {}, diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/SentryPerformanceProviderTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/SentryPerformanceProviderTest.kt index db68009589..ff6a299bed 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/SentryPerformanceProviderTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/SentryPerformanceProviderTest.kt @@ -18,6 +18,7 @@ import org.mockito.kotlin.any import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never +import org.mockito.kotlin.times import org.mockito.kotlin.verify import org.mockito.kotlin.whenever import org.robolectric.annotation.Config @@ -164,7 +165,8 @@ class SentryPerformanceProviderTest { fun `provider properly registers and unregisters ActivityLifecycleCallbacks`() { val provider = fixture.getSut() - verify(fixture.mockContext).registerActivityLifecycleCallbacks(any()) + // It register once for the provider itself and once for the appStartMetrics + verify(fixture.mockContext, times(2)).registerActivityLifecycleCallbacks(any()) provider.onAppStartDone() verify(fixture.mockContext).unregisterActivityLifecycleCallbacks(any()) } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/performance/AppStartMetricsTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/performance/AppStartMetricsTest.kt index 0885024b00..1f2eab8a9a 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/performance/AppStartMetricsTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/performance/AppStartMetricsTest.kt @@ -3,15 +3,25 @@ package io.sentry.android.core.performance import android.app.Application import android.content.ContentProvider import android.os.Build +import android.os.Looper import androidx.test.ext.junit.runners.AndroidJUnit4 +import io.sentry.ITransactionProfiler import io.sentry.android.core.SentryAndroidOptions import io.sentry.android.core.SentryShadowProcess import org.junit.Before import org.junit.runner.RunWith +import org.mockito.kotlin.eq import org.mockito.kotlin.mock +import org.mockito.kotlin.never +import org.mockito.kotlin.times +import org.mockito.kotlin.verify +import org.mockito.kotlin.whenever +import org.robolectric.Shadows import org.robolectric.annotation.Config +import java.util.concurrent.TimeUnit import kotlin.test.Test import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertNotEquals import kotlin.test.assertNull import kotlin.test.assertSame @@ -28,6 +38,7 @@ class AppStartMetricsTest { fun setup() { AppStartMetrics.getInstance().clear() SentryShadowProcess.setStartUptimeMillis(42) + AppStartMetrics.getInstance().isAppLaunchedInForeground = true } @Test @@ -106,4 +117,149 @@ class AppStartMetricsTest { fun `class load time is set`() { assertNotEquals(0, AppStartMetrics.getInstance().classLoadedUptimeMs) } + + @Test + fun `if app is launched in background, appStartTimeSpanWithFallback returns an empty span`() { + AppStartMetrics.getInstance().isAppLaunchedInForeground = false + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.start() + assertTrue(appStartTimeSpan.hasStarted()) + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + Shadows.shadowOf(Looper.getMainLooper()).idle() + + val options = SentryAndroidOptions().apply { + isEnablePerformanceV2 = false + } + + val timeSpan = AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options) + assertFalse(timeSpan.hasStarted()) + } + + @Test + fun `if app is launched in background with perfV2, appStartTimeSpanWithFallback returns an empty span`() { + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.start() + assertTrue(appStartTimeSpan.hasStarted()) + AppStartMetrics.getInstance().isAppLaunchedInForeground = false + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + + val options = SentryAndroidOptions().apply { + isEnablePerformanceV2 = true + } + + val timeSpan = AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options) + assertFalse(timeSpan.hasStarted()) + } + + @Test + fun `if app start span is at most 1 minute, appStartTimeSpanWithFallback returns the app start span`() { + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.start() + appStartTimeSpan.stop() + appStartTimeSpan.setStartedAt(1) + appStartTimeSpan.setStoppedAt(TimeUnit.MINUTES.toMillis(1) + 1) + assertTrue(appStartTimeSpan.hasStarted()) + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + + val options = SentryAndroidOptions().apply { + isEnablePerformanceV2 = true + } + + val timeSpan = AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options) + assertTrue(timeSpan.hasStarted()) + assertSame(appStartTimeSpan, timeSpan) + } + + @Test + fun `if activity is never started, returns an empty span`() { + AppStartMetrics.getInstance().registerApplicationForegroundCheck(mock()) + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.setStartedAt(1) + assertTrue(appStartTimeSpan.hasStarted()) + // Job on main thread checks if activity was launched + Shadows.shadowOf(Looper.getMainLooper()).idle() + + val timeSpan = AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(SentryAndroidOptions()) + assertFalse(timeSpan.hasStarted()) + } + + @Test + fun `if activity is never started, stops app start profiler if running`() { + val profiler = mock() + whenever(profiler.isRunning).thenReturn(true) + AppStartMetrics.getInstance().appStartProfiler = profiler + + AppStartMetrics.getInstance().registerApplicationForegroundCheck(mock()) + // Job on main thread checks if activity was launched + Shadows.shadowOf(Looper.getMainLooper()).idle() + + verify(profiler).close() + } + + @Test + fun `if app start span is longer than 1 minute, appStartTimeSpanWithFallback returns an empty span`() { + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.start() + appStartTimeSpan.stop() + appStartTimeSpan.setStartedAt(1) + appStartTimeSpan.setStoppedAt(TimeUnit.MINUTES.toMillis(1) + 2) + assertTrue(appStartTimeSpan.hasStarted()) + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + + val options = SentryAndroidOptions().apply { + isEnablePerformanceV2 = true + } + + val timeSpan = AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options) + assertFalse(timeSpan.hasStarted()) + } + + @Test + fun `when multiple registerApplicationForegroundCheck, only one callback is registered to application`() { + val application = mock() + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + verify(application, times(1)).registerActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + } + + @Test + fun `when registerApplicationForegroundCheck, a callback is registered to application`() { + val application = mock() + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + verify(application).registerActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + } + + @Test + fun `when registerApplicationForegroundCheck, a job is posted on main thread to unregistered the callback`() { + val application = mock() + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + verify(application).registerActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + verify(application, never()).unregisterActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + Shadows.shadowOf(Looper.getMainLooper()).idle() + verify(application).unregisterActivityLifecycleCallbacks(eq(AppStartMetrics.getInstance())) + } + + @Test + fun `registerApplicationForegroundCheck set foreground state to false if no activity is running`() { + val application = mock() + AppStartMetrics.getInstance().isAppLaunchedInForeground = true + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + assertTrue(AppStartMetrics.getInstance().isAppLaunchedInForeground) + // Main thread performs the check and sets the flag to false if no activity was created + Shadows.shadowOf(Looper.getMainLooper()).idle() + assertFalse(AppStartMetrics.getInstance().isAppLaunchedInForeground) + } + + @Test + fun `registerApplicationForegroundCheck keeps foreground state to true if an activity is running`() { + val application = mock() + AppStartMetrics.getInstance().isAppLaunchedInForeground = true + AppStartMetrics.getInstance().registerApplicationForegroundCheck(application) + assertTrue(AppStartMetrics.getInstance().isAppLaunchedInForeground) + // An activity was created + AppStartMetrics.getInstance().onActivityCreated(mock(), null) + // Main thread performs the check and keeps the flag to true + Shadows.shadowOf(Looper.getMainLooper()).idle() + assertTrue(AppStartMetrics.getInstance().isAppLaunchedInForeground) + } }