diff --git a/CHANGELOG.md b/CHANGELOG.md index 623d596661..4c1b0807c3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Fixes + +- Fix warm start detection ([#3937](https://github.com/getsentry/sentry-java/pull/3937)) + ## 7.19.1 ### Fixes diff --git a/sentry-android-core/api/sentry-android-core.api b/sentry-android-core/api/sentry-android-core.api index 0215008608..02725ba5df 100644 --- a/sentry-android-core/api/sentry-android-core.api +++ b/sentry-android-core/api/sentry-android-core.api @@ -27,8 +27,12 @@ public final class io/sentry/android/core/ActivityLifecycleIntegration : android public fun onActivityCreated (Landroid/app/Activity;Landroid/os/Bundle;)V public fun onActivityDestroyed (Landroid/app/Activity;)V public fun onActivityPaused (Landroid/app/Activity;)V + public fun onActivityPostCreated (Landroid/app/Activity;Landroid/os/Bundle;)V public fun onActivityPostResumed (Landroid/app/Activity;)V + public fun onActivityPostStarted (Landroid/app/Activity;)V + public fun onActivityPreCreated (Landroid/app/Activity;Landroid/os/Bundle;)V public fun onActivityPrePaused (Landroid/app/Activity;)V + public fun onActivityPreStarted (Landroid/app/Activity;)V public fun onActivityResumed (Landroid/app/Activity;)V public fun onActivitySaveInstanceState (Landroid/app/Activity;Landroid/os/Bundle;)V public fun onActivityStarted (Landroid/app/Activity;)V @@ -454,17 +458,21 @@ public class io/sentry/android/core/performance/AppStartMetrics : io/sentry/andr 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 isColdStartValid ()Z public fun onActivityCreated (Landroid/app/Activity;Landroid/os/Bundle;)V + public fun onAppStartSpansSent ()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 restartAppStart (J)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 public fun setClassLoadedUptimeMs (J)V + public fun shouldSendStartMeasurements ()Z } public final class io/sentry/android/core/performance/AppStartMetrics$AppStartType : java/lang/Enum { 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 776695c151..0912051dd7 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 @@ -9,8 +9,7 @@ import android.os.Bundle; import android.os.Handler; import android.os.Looper; -import android.view.View; -import androidx.annotation.NonNull; +import android.os.SystemClock; import io.sentry.FullyDisplayedReporter; import io.sentry.IHub; import io.sentry.IScope; @@ -29,6 +28,7 @@ import io.sentry.TransactionOptions; import io.sentry.android.core.internal.util.ClassUtil; import io.sentry.android.core.internal.util.FirstDrawDoneListener; +import io.sentry.android.core.performance.ActivityLifecycleTimeSpan; import io.sentry.android.core.performance.AppStartMetrics; import io.sentry.android.core.performance.TimeSpan; import io.sentry.protocol.MeasurementValue; @@ -77,8 +77,10 @@ public final class ActivityLifecycleIntegration private @Nullable ISpan appStartSpan; private final @NotNull WeakHashMap ttidSpanMap = new WeakHashMap<>(); private final @NotNull WeakHashMap ttfdSpanMap = new WeakHashMap<>(); + private final @NotNull WeakHashMap activityLifecycleMap = + new WeakHashMap<>(); private @NotNull SentryDate lastPausedTime = new SentryNanotimeDate(new Date(0), 0); - private final @NotNull Handler mainHandler = new Handler(Looper.getMainLooper()); + private long lastPausedUptimeMillis = 0; private @Nullable Future ttfdAutoCloseFuture = null; // WeakHashMap isn't thread safe but ActivityLifecycleCallbacks is only called from the @@ -369,9 +371,32 @@ private void finishTransaction( } } + @Override + public void onActivityPreCreated( + final @NotNull Activity activity, 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 (firstActivityCreated) { + return; + } + lastPausedTime = + hub != null + ? hub.getOptions().getDateProvider().now() + : AndroidDateUtils.getCurrentSentryDateTime(); + lastPausedUptimeMillis = SystemClock.uptimeMillis(); + + final @NotNull ActivityLifecycleTimeSpan timeSpan = new ActivityLifecycleTimeSpan(); + timeSpan.getOnCreate().setStartedAt(lastPausedUptimeMillis); + activityLifecycleMap.put(activity, timeSpan); + } + @Override public synchronized void onActivityCreated( final @NotNull Activity activity, final @Nullable Bundle savedInstanceState) { + if (!isAllActivityCallbacksAvailable) { + onActivityPreCreated(activity, savedInstanceState); + } setColdStart(savedInstanceState); if (hub != null && options != null && options.isEnableScreenTracking()) { final @Nullable String activityClassName = ClassUtil.getClassName(activity); @@ -387,8 +412,38 @@ public synchronized void onActivityCreated( } } + @Override + public void onActivityPostCreated( + final @NotNull Activity activity, final @Nullable Bundle savedInstanceState) { + if (appStartSpan == null) { + activityLifecycleMap.remove(activity); + return; + } + + final @Nullable ActivityLifecycleTimeSpan timeSpan = activityLifecycleMap.get(activity); + if (timeSpan != null) { + timeSpan.getOnCreate().stop(); + timeSpan.getOnCreate().setDescription(activity.getClass().getName() + ".onCreate"); + } + } + + @Override + public void onActivityPreStarted(final @NotNull Activity activity) { + if (appStartSpan == null) { + return; + } + final @Nullable ActivityLifecycleTimeSpan timeSpan = activityLifecycleMap.get(activity); + if (timeSpan != null) { + timeSpan.getOnStart().setStartedAt(SystemClock.uptimeMillis()); + } + } + @Override public synchronized void onActivityStarted(final @NotNull Activity activity) { + if (!isAllActivityCallbacksAvailable) { + onActivityPostCreated(activity, null); + onActivityPreStarted(activity); + } if (performanceEnabled) { // The docs on the screen rendering performance tracing // (https://firebase.google.com/docs/perf-mon/screen-traces?platform=android#definition), @@ -400,74 +455,75 @@ public synchronized void onActivityStarted(final @NotNull Activity activity) { } } + @Override + public void onActivityPostStarted(final @NotNull Activity activity) { + final @Nullable ActivityLifecycleTimeSpan timeSpan = activityLifecycleMap.remove(activity); + if (appStartSpan == null) { + return; + } + if (timeSpan != null) { + timeSpan.getOnStart().stop(); + timeSpan.getOnStart().setDescription(activity.getClass().getName() + ".onStart"); + AppStartMetrics.getInstance().addActivityLifecycleTimeSpans(timeSpan); + } + } + @Override public synchronized void onActivityResumed(final @NotNull Activity activity) { + if (!isAllActivityCallbacksAvailable) { + onActivityPostStarted(activity); + } if (performanceEnabled) { - final @Nullable ISpan ttidSpan = ttidSpanMap.get(activity); final @Nullable ISpan ttfdSpan = ttfdSpanMap.get(activity); - final View rootView = activity.findViewById(android.R.id.content); - if (rootView != null) { + if (activity.getWindow() != null) { FirstDrawDoneListener.registerForNextDraw( - rootView, () -> onFirstFrameDrawn(ttfdSpan, ttidSpan), buildInfoProvider); + activity, () -> onFirstFrameDrawn(ttfdSpan, ttidSpan), buildInfoProvider); } else { // Posting a task to the main thread's handler will make it executed after it finished // its current job. That is, right after the activity draws the layout. - mainHandler.post(() -> onFirstFrameDrawn(ttfdSpan, ttidSpan)); + new Handler(Looper.getMainLooper()).post(() -> onFirstFrameDrawn(ttfdSpan, ttidSpan)); } } } @Override - public void onActivityPostResumed(@NonNull Activity activity) { + public void onActivityPostResumed(@NotNull Activity activity) { // empty override, required to avoid a api-level breaking super.onActivityPostResumed() calls } @Override - public void onActivityPrePaused(@NonNull Activity activity) { + public void onActivityPrePaused(@NotNull Activity activity) { // only executed if API >= 29 otherwise it happens on onActivityPaused - if (isAllActivityCallbacksAvailable) { - // as the SDK may gets (re-)initialized mid activity lifecycle, ensure we set the flag here as - // well - // this ensures any newly launched activity will not use the app start timestamp as txn start - firstActivityCreated = true; - if (hub == null) { - lastPausedTime = AndroidDateUtils.getCurrentSentryDateTime(); - } else { - lastPausedTime = hub.getOptions().getDateProvider().now(); - } - } + // as the SDK may gets (re-)initialized mid activity lifecycle, ensure we set the flag here as + // well + // this ensures any newly launched activity will not use the app start timestamp as txn start + firstActivityCreated = true; + lastPausedTime = + hub != null + ? hub.getOptions().getDateProvider().now() + : AndroidDateUtils.getCurrentSentryDateTime(); + lastPausedUptimeMillis = SystemClock.uptimeMillis(); } @Override public synchronized void onActivityPaused(final @NotNull Activity activity) { // only executed if API < 29 otherwise it happens on onActivityPrePaused if (!isAllActivityCallbacksAvailable) { - // as the SDK may gets (re-)initialized mid activity lifecycle, ensure we set the flag here as - // well - // this ensures any newly launched activity will not use the app start timestamp as txn start - firstActivityCreated = true; - if (hub == null) { - lastPausedTime = AndroidDateUtils.getCurrentSentryDateTime(); - } else { - lastPausedTime = hub.getOptions().getDateProvider().now(); - } + onActivityPrePaused(activity); } } @Override - public synchronized void onActivityStopped(final @NotNull Activity activity) { - // no-op - } + public void onActivityStopped(final @NotNull Activity activity) {} @Override - public synchronized void onActivitySaveInstanceState( - final @NotNull Activity activity, final @NotNull Bundle outState) { - // no-op - } + public void onActivitySaveInstanceState( + final @NotNull Activity activity, final @NotNull Bundle outState) {} @Override public synchronized void onActivityDestroyed(final @NotNull Activity activity) { + activityLifecycleMap.remove(activity); if (performanceEnabled) { // in case the appStartSpan isn't completed yet, we finish it as cancelled to avoid @@ -494,10 +550,20 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { } // clear it up, so we don't start again for the same activity if the activity is in the - // activity - // stack still. + // activity stack still. // if the activity is opened again and not in memory, transactions will be created normally. activitiesWithOngoingTransactions.remove(activity); + + if (activitiesWithOngoingTransactions.isEmpty()) { + clear(); + } + } + + private void clear() { + firstActivityCreated = false; + lastPausedTime = new SentryNanotimeDate(new Date(0), 0); + lastPausedUptimeMillis = 0; + activityLifecycleMap.clear(); } private void finishSpan(final @Nullable ISpan span) { @@ -604,6 +670,17 @@ WeakHashMap getActivitiesWithOngoingTransactions() { return activitiesWithOngoingTransactions; } + @TestOnly + @NotNull + WeakHashMap getActivityLifecycleMap() { + return activityLifecycleMap; + } + + @TestOnly + void setFirstActivityCreated(boolean firstActivityCreated) { + this.firstActivityCreated = firstActivityCreated; + } + @TestOnly @NotNull ActivityFramesTracker getActivityFramesTracker() { @@ -629,20 +706,17 @@ 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 - // SentryPerformanceProvider sets this already - // pre-performance-v2: back-fill with best guess - if (options != null && !options.isEnablePerformanceV2()) { + final @NotNull TimeSpan appStartSpan = AppStartMetrics.getInstance().getAppStartTimeSpan(); + // If the app start span already started and stopped, it means the app restarted without + // killing the process, so we are in a warm start + // If the app has an invalid cold start, it means it was started in the background, like + // via BroadcastReceiver, so we consider it a warm start + if ((appStartSpan.hasStarted() && appStartSpan.hasStopped()) + || (!AppStartMetrics.getInstance().isColdStartValid())) { + AppStartMetrics.getInstance().restartAppStart(lastPausedUptimeMillis); + AppStartMetrics.getInstance().setAppStartType(AppStartMetrics.AppStartType.WARM); + } else { AppStartMetrics.getInstance() .setAppStartType( savedInstanceState == null diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java b/sentry-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java index 00ba9122e7..242902b339 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java @@ -78,12 +78,13 @@ public SentryEvent process(@NotNull SentryEvent event, @NotNull Hint hint) { return transaction; } + final @NotNull AppStartMetrics appStartMetrics = AppStartMetrics.getInstance(); // the app start measurement is only sent once and only if the transaction has // the app.start span, which is automatically created by the SDK. if (hasAppStartSpan(transaction)) { - if (!sentStartMeasurement) { + if (appStartMetrics.shouldSendStartMeasurements()) { final @NotNull TimeSpan appStartTimeSpan = - AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options); + appStartMetrics.getAppStartTimeSpanWithFallback(options); final long appStartUpDurationMs = appStartTimeSpan.getDurationMs(); // if appStartUpDurationMs is 0, metrics are not ready to be sent @@ -93,14 +94,14 @@ public SentryEvent process(@NotNull SentryEvent event, @NotNull Hint hint) { (float) appStartUpDurationMs, MeasurementUnit.Duration.MILLISECOND.apiName()); final String appStartKey = - AppStartMetrics.getInstance().getAppStartType() == AppStartMetrics.AppStartType.COLD + appStartMetrics.getAppStartType() == AppStartMetrics.AppStartType.COLD ? MeasurementValue.KEY_APP_START_COLD : MeasurementValue.KEY_APP_START_WARM; transaction.getMeasurements().put(appStartKey, value); - attachColdAppStartSpans(AppStartMetrics.getInstance(), transaction); - sentStartMeasurement = true; + attachAppStartSpans(appStartMetrics, transaction); + appStartMetrics.onAppStartSpansSent(); } } @@ -110,9 +111,7 @@ public SentryEvent process(@NotNull SentryEvent event, @NotNull Hint hint) { transaction.getContexts().setApp(appContext); } final String appStartType = - AppStartMetrics.getInstance().getAppStartType() == AppStartMetrics.AppStartType.COLD - ? "cold" - : "warm"; + appStartMetrics.getAppStartType() == AppStartMetrics.AppStartType.COLD ? "cold" : "warm"; appContext.setStartType(appStartType); } @@ -217,11 +216,11 @@ private boolean hasAppStartSpan(final @NotNull SentryTransaction txn) { || context.getOperation().equals(APP_START_WARM)); } - private void attachColdAppStartSpans( + private void attachAppStartSpans( final @NotNull AppStartMetrics appStartMetrics, final @NotNull SentryTransaction txn) { - // data will be filled only for cold app starts - if (appStartMetrics.getAppStartType() != AppStartMetrics.AppStartType.COLD) { + // data will be filled only for cold and warm app starts + if (appStartMetrics.getAppStartType() == AppStartMetrics.AppStartType.UNKNOWN) { return; } @@ -235,76 +234,79 @@ private void attachColdAppStartSpans( @Nullable SpanId parentSpanId = null; final @NotNull List spans = txn.getSpans(); for (final @NotNull SentrySpan span : spans) { - if (span.getOp().contentEquals(APP_START_COLD)) { + if (span.getOp().contentEquals(APP_START_COLD) + || span.getOp().contentEquals(APP_START_WARM)) { parentSpanId = span.getSpanId(); break; } } - // Process init - final long classInitUptimeMs = appStartMetrics.getClassLoadedUptimeMs(); - final @NotNull TimeSpan appStartTimeSpan = appStartMetrics.getAppStartTimeSpan(); - if (appStartTimeSpan.hasStarted() - && Math.abs(classInitUptimeMs - appStartTimeSpan.getStartUptimeMs()) - <= MAX_PROCESS_INIT_APP_START_DIFF_MS) { - final @NotNull TimeSpan processInitTimeSpan = new TimeSpan(); - processInitTimeSpan.setStartedAt(appStartTimeSpan.getStartUptimeMs()); - processInitTimeSpan.setStartUnixTimeMs(appStartTimeSpan.getStartTimestampMs()); - - processInitTimeSpan.setStoppedAt(classInitUptimeMs); - processInitTimeSpan.setDescription("Process Initialization"); - - txn.getSpans() - .add( - timeSpanToSentrySpan( - processInitTimeSpan, parentSpanId, traceId, APP_METRICS_PROCESS_INIT_OP)); - } + // We include process init, content providers and application.onCreate spans only on cold start + if (appStartMetrics.getAppStartType() == AppStartMetrics.AppStartType.COLD) { + // Process init + final long classInitUptimeMs = appStartMetrics.getClassLoadedUptimeMs(); + final @NotNull TimeSpan appStartTimeSpan = appStartMetrics.getAppStartTimeSpan(); + if (appStartTimeSpan.hasStarted() + && Math.abs(classInitUptimeMs - appStartTimeSpan.getStartUptimeMs()) + <= MAX_PROCESS_INIT_APP_START_DIFF_MS) { + final @NotNull TimeSpan processInitTimeSpan = new TimeSpan(); + processInitTimeSpan.setStartedAt(appStartTimeSpan.getStartUptimeMs()); + processInitTimeSpan.setStartUnixTimeMs(appStartTimeSpan.getStartTimestampMs()); + + processInitTimeSpan.setStoppedAt(classInitUptimeMs); + processInitTimeSpan.setDescription("Process Initialization"); - // Content Providers - final @NotNull List contentProviderOnCreates = - appStartMetrics.getContentProviderOnCreateTimeSpans(); - if (!contentProviderOnCreates.isEmpty()) { - for (final @NotNull TimeSpan contentProvider : contentProviderOnCreates) { txn.getSpans() .add( timeSpanToSentrySpan( - contentProvider, parentSpanId, traceId, APP_METRICS_CONTENT_PROVIDER_OP)); + processInitTimeSpan, parentSpanId, traceId, APP_METRICS_PROCESS_INIT_OP)); } - } - // Application.onCreate - final @NotNull TimeSpan appOnCreate = appStartMetrics.getApplicationOnCreateTimeSpan(); - if (appOnCreate.hasStopped()) { - txn.getSpans() - .add( - timeSpanToSentrySpan(appOnCreate, parentSpanId, traceId, APP_METRICS_APPLICATION_OP)); + // Content Providers + final @NotNull List contentProviderOnCreates = + appStartMetrics.getContentProviderOnCreateTimeSpans(); + if (!contentProviderOnCreates.isEmpty()) { + for (final @NotNull TimeSpan contentProvider : contentProviderOnCreates) { + txn.getSpans() + .add( + timeSpanToSentrySpan( + contentProvider, parentSpanId, traceId, APP_METRICS_CONTENT_PROVIDER_OP)); + } + } + + // Application.onCreate + final @NotNull TimeSpan appOnCreate = appStartMetrics.getApplicationOnCreateTimeSpan(); + if (appOnCreate.hasStopped()) { + txn.getSpans() + .add( + timeSpanToSentrySpan( + appOnCreate, parentSpanId, traceId, APP_METRICS_APPLICATION_OP)); + } } // Activities final @NotNull List activityLifecycleTimeSpans = appStartMetrics.getActivityLifecycleTimeSpans(); - if (!activityLifecycleTimeSpans.isEmpty()) { - for (ActivityLifecycleTimeSpan activityTimeSpan : activityLifecycleTimeSpans) { - if (activityTimeSpan.getOnCreate().hasStarted() - && activityTimeSpan.getOnCreate().hasStopped()) { - txn.getSpans() - .add( - timeSpanToSentrySpan( - activityTimeSpan.getOnCreate(), - parentSpanId, - traceId, - APP_METRICS_ACTIVITIES_OP)); - } - if (activityTimeSpan.getOnStart().hasStarted() - && activityTimeSpan.getOnStart().hasStopped()) { - txn.getSpans() - .add( - timeSpanToSentrySpan( - activityTimeSpan.getOnStart(), - parentSpanId, - traceId, - APP_METRICS_ACTIVITIES_OP)); - } + for (ActivityLifecycleTimeSpan activityTimeSpan : activityLifecycleTimeSpans) { + if (activityTimeSpan.getOnCreate().hasStarted() + && activityTimeSpan.getOnCreate().hasStopped()) { + txn.getSpans() + .add( + timeSpanToSentrySpan( + activityTimeSpan.getOnCreate(), + parentSpanId, + traceId, + APP_METRICS_ACTIVITIES_OP)); + } + if (activityTimeSpan.getOnStart().hasStarted() + && activityTimeSpan.getOnStart().hasStopped()) { + txn.getSpans() + .add( + timeSpanToSentrySpan( + activityTimeSpan.getOnStart(), + parentSpanId, + traceId, + APP_METRICS_ACTIVITIES_OP)); } } } 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 971ead378f..0aa946c255 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 @@ -9,14 +9,14 @@ import android.content.pm.ProviderInfo; import android.net.Uri; import android.os.Build; -import android.os.Bundle; +import android.os.Handler; +import android.os.Looper; import android.os.Process; import android.os.SystemClock; import androidx.annotation.NonNull; import io.sentry.ILogger; import io.sentry.ITransactionProfiler; import io.sentry.JsonSerializer; -import io.sentry.NoOpLogger; import io.sentry.SentryAppStartProfilingOptions; import io.sentry.SentryExecutorService; import io.sentry.SentryLevel; @@ -25,7 +25,6 @@ import io.sentry.android.core.internal.util.FirstDrawDoneListener; import io.sentry.android.core.internal.util.SentryFrameMetricsCollector; import io.sentry.android.core.performance.ActivityLifecycleCallbacksAdapter; -import io.sentry.android.core.performance.ActivityLifecycleTimeSpan; import io.sentry.android.core.performance.AppStartMetrics; import io.sentry.android.core.performance.TimeSpan; import java.io.BufferedReader; @@ -34,7 +33,6 @@ import java.io.FileNotFoundException; import java.io.InputStreamReader; import java.io.Reader; -import java.util.WeakHashMap; import java.util.concurrent.atomic.AtomicBoolean; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; @@ -206,101 +204,23 @@ private void onAppLaunched( activityCallback = new ActivityLifecycleCallbacksAdapter() { - final WeakHashMap activityLifecycleMap = - new WeakHashMap<>(); - - @Override - public void onActivityPreCreated( - @NonNull Activity activity, @Nullable Bundle savedInstanceState) { - final long now = SystemClock.uptimeMillis(); - if (appStartMetrics.getAppStartTimeSpan().hasStopped()) { - return; - } - - final ActivityLifecycleTimeSpan timeSpan = new ActivityLifecycleTimeSpan(); - timeSpan.getOnCreate().setStartedAt(now); - activityLifecycleMap.put(activity, timeSpan); - } - - @Override - public void onActivityCreated( - @NonNull Activity activity, @Nullable Bundle savedInstanceState) { - if (appStartMetrics.getAppStartType() == AppStartMetrics.AppStartType.UNKNOWN) { - appStartMetrics.setAppStartType( - savedInstanceState == null - ? AppStartMetrics.AppStartType.COLD - : AppStartMetrics.AppStartType.WARM); - } - } - - @Override - public void onActivityPostCreated( - @NonNull Activity activity, @Nullable Bundle savedInstanceState) { - if (appStartMetrics.getAppStartTimeSpan().hasStopped()) { - return; - } - - final @Nullable ActivityLifecycleTimeSpan timeSpan = activityLifecycleMap.get(activity); - if (timeSpan != null) { - timeSpan.getOnCreate().stop(); - timeSpan.getOnCreate().setDescription(activity.getClass().getName() + ".onCreate"); - } - } - - @Override - public void onActivityPreStarted(@NonNull Activity activity) { - final long now = SystemClock.uptimeMillis(); - if (appStartMetrics.getAppStartTimeSpan().hasStopped()) { - return; - } - final @Nullable ActivityLifecycleTimeSpan timeSpan = activityLifecycleMap.get(activity); - if (timeSpan != null) { - timeSpan.getOnStart().setStartedAt(now); - } - } - @Override public void onActivityStarted(@NonNull Activity activity) { if (firstDrawDone.get()) { return; } - FirstDrawDoneListener.registerForNextDraw( - activity, - () -> { - if (firstDrawDone.compareAndSet(false, true)) { - onAppStartDone(); - } - }, - // as the SDK isn't initialized yet, we don't have access to SentryOptions - new BuildInfoProvider(NoOpLogger.getInstance())); - } - - @Override - public void onActivityPostStarted(@NonNull Activity activity) { - final @Nullable ActivityLifecycleTimeSpan timeSpan = - activityLifecycleMap.remove(activity); - if (appStartMetrics.getAppStartTimeSpan().hasStopped()) { - return; - } - if (timeSpan != null) { - timeSpan.getOnStart().stop(); - timeSpan.getOnStart().setDescription(activity.getClass().getName() + ".onStart"); - - appStartMetrics.addActivityLifecycleTimeSpans(timeSpan); + if (activity.getWindow() != null) { + FirstDrawDoneListener.registerForNextDraw( + activity, () -> onAppStartDone(), buildInfoProvider); + } else { + new Handler(Looper.getMainLooper()).post(() -> onAppStartDone()); } } - - @Override - public void onActivityDestroyed(@NonNull Activity activity) { - // safety net for activities which were created but never stopped - activityLifecycleMap.remove(activity); - } }; app.registerActivityLifecycleCallbacks(activityCallback); } - @TestOnly synchronized void onAppStartDone() { final @NotNull AppStartMetrics appStartMetrics = AppStartMetrics.getInstance(); appStartMetrics.getSdkInitTimeSpan().stop(); @@ -312,10 +232,4 @@ synchronized void onAppStartDone() { } } } - - @TestOnly - @Nullable - Application.ActivityLifecycleCallbacks getActivityCallback() { - return activityCallback; - } } 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 461ee5eed6..2e249d6dcc 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 @@ -57,6 +57,7 @@ public enum AppStartType { private @Nullable SentryDate onCreateTime = null; private boolean appLaunchTooLong = false; private boolean isCallbackRegistered = false; + private boolean shouldSendStartMeasurements = true; public static @NotNull AppStartMetrics getInstance() { @@ -115,6 +116,10 @@ public boolean isAppLaunchedInForeground() { return appLaunchedInForeground; } + public boolean isColdStartValid() { + return appLaunchedInForeground && !appLaunchTooLong; + } + @VisibleForTesting public void setAppLaunchedInForeground(final boolean appLaunchedInForeground) { this.appLaunchedInForeground = appLaunchedInForeground; @@ -126,21 +131,41 @@ public void setAppLaunchedInForeground(final boolean appLaunchedInForeground) { * @return A sorted list of all onCreate calls */ public @NotNull List getContentProviderOnCreateTimeSpans() { - final List measurements = new ArrayList<>(contentProviderOnCreates.values()); - Collections.sort(measurements); - return measurements; + final List spans = new ArrayList<>(contentProviderOnCreates.values()); + Collections.sort(spans); + return spans; } public @NotNull List getActivityLifecycleTimeSpans() { - final List measurements = new ArrayList<>(activityLifecycles); - Collections.sort(measurements); - return measurements; + final List spans = new ArrayList<>(activityLifecycles); + Collections.sort(spans); + return spans; } public void addActivityLifecycleTimeSpans(final @NotNull ActivityLifecycleTimeSpan timeSpan) { activityLifecycles.add(timeSpan); } + public void onAppStartSpansSent() { + shouldSendStartMeasurements = false; + contentProviderOnCreates.clear(); + activityLifecycles.clear(); + } + + public boolean shouldSendStartMeasurements() { + return shouldSendStartMeasurements; + } + + public void restartAppStart(final long uptimeMillis) { + shouldSendStartMeasurements = true; + appLaunchTooLong = false; + appLaunchedInForeground = true; + appStartSpan.reset(); + appStartSpan.start(); + appStartSpan.setStartedAt(uptimeMillis); + CLASS_LOADED_UPTIME_MS = appStartSpan.getStartUptimeMs(); + } + public long getClassLoadedUptimeMs() { return CLASS_LOADED_UPTIME_MS; } @@ -151,24 +176,20 @@ public long getClassLoadedUptimeMs() { */ public @NotNull TimeSpan getAppStartTimeSpanWithFallback( final @NotNull SentryAndroidOptions options) { + // If the app launch took too long or it was launched in the background we return an empty span + if (!isColdStartValid()) { + return new TimeSpan(); + } if (options.isEnablePerformanceV2()) { // Only started when sdk version is >= N final @NotNull TimeSpan appStartSpan = getAppStartTimeSpan(); if (appStartSpan.hasStarted()) { - return validateAppStartSpan(appStartSpan); + return appStartSpan; } } // fallback: use sdk init time span, as it will always have a start time set - 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; + return getSdkInitTimeSpan(); } @TestOnly @@ -188,6 +209,7 @@ public void clear() { appLaunchedInForeground = false; onCreateTime = null; isCallbackRegistered = false; + shouldSendStartMeasurements = true; } public @Nullable ITransactionProfiler getAppStartProfiler() { 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 addeb94819..be000b7517 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 @@ -338,15 +338,27 @@ class ActivityLifecycleIntegrationTest { sut.onActivityPostResumed(activity) verify(fixture.hub, never()).captureTransaction( - check { - assertEquals(SpanStatus.OK, it.status) - }, + any(), anyOrNull(), anyOrNull(), anyOrNull() ) } + @Test + fun `When tracing auto finish is disabled, do not finish transaction`() { + val sut = fixture.getSut(initializer = { + it.tracesSampleRate = 1.0 + it.isEnableActivityLifecycleTracingAutoFinish = false + }) + sut.register(fixture.hub, fixture.options) + val activity = mock() + sut.onActivityCreated(activity, fixture.bundle) + // We don't schedule the transaction to finish + assertFalse(fixture.transaction.isFinishing()) + assertFalse(fixture.transaction.isFinished) + } + @Test fun `When tracing has status, do not overwrite it`() { val sut = fixture.getSut() @@ -371,20 +383,6 @@ class ActivityLifecycleIntegrationTest { ) } - @Test - fun `When tracing auto finish is disabled, do not finish transaction`() { - val sut = fixture.getSut(initializer = { - it.tracesSampleRate = 1.0 - it.isEnableActivityLifecycleTracingAutoFinish = false - }) - sut.register(fixture.hub, fixture.options) - val activity = mock() - sut.onActivityCreated(activity, fixture.bundle) - sut.onActivityPostResumed(activity) - - verify(fixture.hub, never()).captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) - } - @Test fun `When tracing is disabled, do not finish transaction`() { val sut = fixture.getSut() @@ -467,7 +465,7 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When Activity is destroyed, sets ttidSpan status to deadline_exceeded and finish it`() { + fun `When Activity is destroyed, finish ttidSpan with deadline_exceeded and remove from map`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) @@ -476,31 +474,17 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, fixture.bundle) + assertNotNull(sut.ttidSpanMap[activity]) sut.onActivityDestroyed(activity) val span = fixture.transaction.children.first { it.operation == ActivityLifecycleIntegration.TTID_OP } assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status) assertTrue(span.isFinished) - } - - @Test - fun `When Activity is destroyed, sets ttidSpan to null`() { - val sut = fixture.getSut() - fixture.options.tracesSampleRate = 1.0 - sut.register(fixture.hub, fixture.options) - - setAppStartTime() - - val activity = mock() - sut.onActivityCreated(activity, fixture.bundle) - assertNotNull(sut.ttidSpanMap[activity]) - - sut.onActivityDestroyed(activity) assertNull(sut.ttidSpanMap[activity]) } @Test - fun `When Activity is destroyed, sets ttfdSpan status to deadline_exceeded and finish it`() { + fun `When Activity is destroyed, finish ttfdSpan with deadline_exceeded and remove from map`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 fixture.options.isEnableTimeToFullDisplayTracing = true @@ -510,27 +494,12 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, fixture.bundle) + assertNotNull(sut.ttfdSpanMap[activity]) sut.onActivityDestroyed(activity) val span = fixture.transaction.children.first { it.operation == ActivityLifecycleIntegration.TTFD_OP } assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status) assertTrue(span.isFinished) - } - - @Test - fun `When Activity is destroyed, sets ttfdSpan to null`() { - val sut = fixture.getSut() - fixture.options.tracesSampleRate = 1.0 - fixture.options.isEnableTimeToFullDisplayTracing = true - sut.register(fixture.hub, fixture.options) - - setAppStartTime() - - val activity = mock() - sut.onActivityCreated(activity, fixture.bundle) - assertNotNull(sut.ttfdSpanMap[activity]) - - sut.onActivityDestroyed(activity) assertNull(sut.ttfdSpanMap[activity]) } @@ -547,7 +516,7 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `do not stop transaction on resumed if API 29`() { + fun `do not stop transaction on resumed`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) @@ -560,31 +529,11 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `do not stop transaction on resumed if API less than 29 and ttid and ttfd are finished`() { - val sut = fixture.getSut(Build.VERSION_CODES.P) - fixture.options.tracesSampleRate = 1.0 - fixture.options.isEnableTimeToFullDisplayTracing = true - sut.register(fixture.hub, fixture.options) - - val activity = mock() - sut.onActivityCreated(activity, mock()) - sut.ttidSpanMap.values.first().finish() - sut.ttfdSpanMap.values.first().finish() - sut.onActivityResumed(activity) - - verify(fixture.hub, never()).captureTransaction(any(), any(), anyOrNull(), anyOrNull()) - } - - @Test - fun `start transaction on created if API less than 29`() { - val sut = fixture.getSut(Build.VERSION_CODES.P) + fun `start transaction on created`() { + val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) - - setAppStartTime() - - val activity = mock() - sut.onActivityCreated(activity, mock()) + sut.onActivityCreated(mock(), mock()) verify(fixture.hub).startTransaction(any(), any()) } @@ -594,6 +543,7 @@ class ActivityLifecycleIntegrationTest { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 fixture.options.isEnableTimeToFullDisplayTracing = true + fixture.options.idleTimeout = 0 sut.register(fixture.hub, fixture.options) val activity = mock() @@ -602,6 +552,7 @@ class ActivityLifecycleIntegrationTest { sut.ttidSpanMap.values.first().finish() sut.onActivityResumed(activity) sut.onActivityPostResumed(activity) + runFirstDraw(fixture.createView()) assertNotNull(ttfd) assertFalse(ttfd.isFinished) @@ -682,15 +633,18 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When firstActivityCreated is true, start transaction with given appStartTime`() { + fun `When firstActivityCreated is false, start transaction with given appStartTime`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime(date) + fixture.options.dateProvider = SentryDateProvider { date } val activity = mock() + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) // call only once @@ -703,15 +657,17 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When firstActivityCreated is true and app start sampling decision is set, start transaction with isAppStart true`() { + fun `When firstActivityCreated is false and app start sampling decision is set, start transaction with isAppStart true`() { AppStartMetrics.getInstance().appStartSamplingDecision = mock() val sut = fixture.getSut { it.tracesSampleRate = 1.0 } sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime(date) val activity = mock() + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) verify(fixture.hub).startTransaction( @@ -724,9 +680,10 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When firstActivityCreated is true and app start sampling decision is not set, start transaction with isAppStart false`() { + fun `When firstActivityCreated is false and app start sampling decision is not set, start transaction with isAppStart false`() { val sut = fixture.getSut { it.tracesSampleRate = 1.0 } sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) val date2 = SentryNanotimeDate(Date(2), 2) @@ -735,6 +692,7 @@ class ActivityLifecycleIntegrationTest { val activity = mock() // The activity onCreate date will be ignored fixture.options.dateProvider = SentryDateProvider { date2 } + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) verify(fixture.hub).startTransaction( @@ -748,65 +706,71 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When firstActivityCreated is false and app start sampling decision is set, start transaction with isAppStart false`() { + fun `When firstActivityCreated is true and app start sampling decision is set, start transaction with isAppStart false`() { AppStartMetrics.getInstance().appStartSamplingDecision = mock() val sut = fixture.getSut { it.tracesSampleRate = 1.0 } sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(true) + val date = SentryNanotimeDate(Date(1), 0) + setAppStartTime(date) val activity = mock() + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) verify(fixture.hub).startTransaction(any(), check { assertFalse(it.isAppStartTransaction) }) } @Test - fun `When firstActivityCreated is true, do not create app start span if not foregroundImportance`() { - val sut = fixture.getSut(importance = RunningAppProcessInfo.IMPORTANCE_BACKGROUND) + fun `When firstActivityCreated is false and no app start time is set, default to onActivityPreCreated time`() { + val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) // usually set by SentryPerformanceProvider val date = SentryNanotimeDate(Date(1), 0) - setAppStartTime(date) - AppStartMetrics.getInstance().sdkInitTimeSpan.setStoppedAt(2) + val date2 = SentryNanotimeDate(Date(2), 2) val activity = mock() + // Activity onCreate date will be used + fixture.options.dateProvider = SentryDateProvider { date2 } + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) - // call only once verify(fixture.hub).startTransaction( any(), - check { assertNotEquals(date, it.startTimestamp) } + check { + assertEquals(date2.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) + assertNotEquals(date.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) + } ) } @Test - fun `When firstActivityCreated is true and no app start time is set, default to onActivityCreated time`() { - val sut = fixture.getSut() + fun `When not foregroundImportance, do not create app start span`() { + val sut = fixture.getSut(importance = RunningAppProcessInfo.IMPORTANCE_BACKGROUND) 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) + setAppStartTime(date) val activity = mock() - // Activity onCreate date will be used - fixture.options.dateProvider = SentryDateProvider { date2 } + sut.onActivityPreCreated(activity, fixture.bundle) sut.onActivityCreated(activity, fixture.bundle) + // call only once verify(fixture.hub).startTransaction( any(), - check { - assertEquals(date2.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) - assertNotEquals(date.nanoTimestamp(), it.startTimestamp!!.nanoTimestamp()) - } + check { 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) + val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) @@ -822,12 +786,10 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, fixture.bundle) - val appStartSpanCount = fixture.transaction.children.count { - it.spanContext.operation.startsWith("app.start.warm") && - it.startDate.nanoTimestamp() == startDate.nanoTimestamp() && - it.finishDate!!.nanoTimestamp() == endDate!!.nanoTimestamp() - } - assertEquals(1, appStartSpanCount) + val appStartSpan = fixture.transaction.children.first { it.operation.startsWith("app.start.warm") } + assertEquals(startDate.nanoTimestamp(), appStartSpan.startDate.nanoTimestamp()) + assertEquals(endDate!!.nanoTimestamp(), appStartSpan.finishDate!!.nanoTimestamp()) + assertTrue(appStartSpan.isFinished) } @Test @@ -921,10 +883,11 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When firstActivityCreated is true, start app start warm span with given appStartTime`() { + fun `When firstActivityCreated is false and bundle is not null, start app start warm span with given appStartTime`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime(date) @@ -934,48 +897,16 @@ class ActivityLifecycleIntegrationTest { val span = fixture.transaction.children.first() assertEquals(span.operation, "app.start.warm") - assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) - } - - @Test - fun `When firstActivityCreated is true, start app start cold span with given appStartTime`() { - val sut = fixture.getSut() - 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 span = fixture.transaction.children.first() - assertEquals(span.operation, "app.start.cold") - assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) - } - - @Test - fun `When firstActivityCreated is true, start app start span with Warm description`() { - val sut = fixture.getSut() - 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, fixture.bundle) - - val span = fixture.transaction.children.first() assertEquals(span.description, "Warm Start") assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) } @Test - fun `When firstActivityCreated is true, start app start span with Cold description`() { + fun `When firstActivityCreated is false and bundle is not null, start app start cold span with given appStartTime`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime(date) @@ -984,15 +915,17 @@ class ActivityLifecycleIntegrationTest { sut.onActivityCreated(activity, null) val span = fixture.transaction.children.first() + assertEquals(span.operation, "app.start.cold") assertEquals(span.description, "Cold Start") 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`() { + fun `When firstActivityCreated is false and app started more than 1 minute ago, start app with Warm start`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) val duration = TimeUnit.MINUTES.toMillis(1) + 2 @@ -1003,18 +936,19 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, null) - val appStartSpan = fixture.transaction.children.firstOrNull { - it.description == "Cold Start" - } - assertNull(appStartSpan) + val span = fixture.transaction.children.first() + assertEquals(span.operation, "app.start.warm") + assertEquals(span.description, "Warm Start") + assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) } @Test - fun `When firstActivityCreated is true and app started in background, app start spans are dropped`() { + fun `When firstActivityCreated is false and app started in background, start app with Warm start`() { val sut = fixture.getSut() AppStartMetrics.getInstance().isAppLaunchedInForeground = false fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(false) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime(date) @@ -1022,17 +956,18 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, null) - val appStartSpan = fixture.transaction.children.firstOrNull { - it.description == "Cold Start" - } - assertNull(appStartSpan) + val span = fixture.transaction.children.first() + assertEquals(span.operation, "app.start.warm") + assertEquals(span.description, "Warm Start") + assertEquals(span.startDate.nanoTimestamp(), date.nanoTimestamp()) } @Test - fun `When firstActivityCreated is false, start transaction but not with given appStartTime`() { + fun `When firstActivityCreated is true, start transaction but not with given appStartTime`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(true) val date = SentryNanotimeDate(Date(1), 0) setAppStartTime() @@ -1041,11 +976,6 @@ class ActivityLifecycleIntegrationTest { // First invocation: we expect to start a transaction with the appStartTime sut.onActivityCreated(activity, fixture.bundle) sut.onActivityPostResumed(activity) - assertEquals(date.nanoTimestamp(), fixture.transaction.startDate.nanoTimestamp()) - - val newActivity = mock() - // Second invocation: we expect to start a transaction with a different start timestamp - sut.onActivityCreated(newActivity, fixture.bundle) assertNotEquals(date.nanoTimestamp(), fixture.transaction.startDate.nanoTimestamp()) } @@ -1493,6 +1423,151 @@ class ActivityLifecycleIntegrationTest { assertEquals(now.nanoTimestamp(), fixture.transaction.startDate.nanoTimestamp()) } + @Test + fun `On activity preCreated onCreate span is created`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + val date = SentryNanotimeDate(Date(1), 0) + setAppStartTime(date) + + assertTrue(sut.activityLifecycleMap.isEmpty()) + + val activity = mock() + // Activity onCreate date will be used + sut.onActivityPreCreated(activity, fixture.bundle) + // sut.onActivityCreated(activity, fixture.bundle) + + assertFalse(sut.activityLifecycleMap.isEmpty()) + assertTrue(sut.activityLifecycleMap.values.first().onCreate.hasStarted()) + assertFalse(sut.activityLifecycleMap.values.first().onCreate.hasStopped()) + } + + @Test + fun `Creates activity lifecycle spans`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + val appStartDate = SentryNanotimeDate(Date(1), 0) + val startDate = SentryNanotimeDate(Date(2), 0) + val appStartMetrics = AppStartMetrics.getInstance() + val activity = mock() + fixture.options.dateProvider = SentryDateProvider { startDate } + setAppStartTime(appStartDate) + + sut.register(fixture.hub, fixture.options) + assertTrue(sut.activityLifecycleMap.isEmpty()) + + sut.onActivityPreCreated(activity, null) + + assertFalse(sut.activityLifecycleMap.isEmpty()) + val activityLifecycleSpan = sut.activityLifecycleMap.values.first() + assertTrue(activityLifecycleSpan.onCreate.hasStarted()) + assertEquals(startDate.nanoTimestamp(), sut.getProperty("lastPausedTime").nanoTimestamp()) + + sut.onActivityCreated(activity, null) + assertNotNull(sut.appStartSpan) + + sut.onActivityPostCreated(activity, null) + assertTrue(activityLifecycleSpan.onCreate.hasStopped()) + + sut.onActivityPreStarted(activity) + assertTrue(activityLifecycleSpan.onStart.hasStarted()) + + sut.onActivityStarted(activity) + assertTrue(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + + sut.onActivityPostStarted(activity) + assertTrue(activityLifecycleSpan.onStart.hasStopped()) + assertFalse(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + } + + @Test + fun `Creates activity lifecycle spans on API lower than 29`() { + val sut = fixture.getSut(apiVersion = Build.VERSION_CODES.P) + fixture.options.tracesSampleRate = 1.0 + val appStartDate = SentryNanotimeDate(Date(1), 0) + val startDate = SentryNanotimeDate(Date(2), 0) + val appStartMetrics = AppStartMetrics.getInstance() + val activity = mock() + fixture.options.dateProvider = SentryDateProvider { startDate } + setAppStartTime(appStartDate) + + sut.register(fixture.hub, fixture.options) + assertTrue(sut.activityLifecycleMap.isEmpty()) + + sut.onActivityCreated(activity, null) + + assertFalse(sut.activityLifecycleMap.isEmpty()) + val activityLifecycleSpan = sut.activityLifecycleMap.values.first() + assertTrue(activityLifecycleSpan.onCreate.hasStarted()) + assertEquals(startDate.nanoTimestamp(), sut.getProperty("lastPausedTime").nanoTimestamp()) + assertNotNull(sut.appStartSpan) + + sut.onActivityStarted(activity) + assertTrue(activityLifecycleSpan.onCreate.hasStopped()) + assertTrue(activityLifecycleSpan.onStart.hasStarted()) + assertTrue(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + + sut.onActivityResumed(activity) + assertTrue(activityLifecycleSpan.onStart.hasStopped()) + assertFalse(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + } + + @Test + fun `Does not add activity lifecycle spans when firstActivityCreated is true`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + val appStartDate = SentryNanotimeDate(Date(1), 0) + val startDate = SentryNanotimeDate(Date(2), 0) + val appStartMetrics = AppStartMetrics.getInstance() + val activity = mock() + fixture.options.dateProvider = SentryDateProvider { startDate } + setAppStartTime(appStartDate) + sut.register(fixture.hub, fixture.options) + sut.setFirstActivityCreated(true) + + sut.onActivityPreCreated(activity, null) + sut.onActivityCreated(activity, null) + sut.onActivityPostCreated(activity, null) + sut.onActivityPreStarted(activity) + sut.onActivityStarted(activity) + sut.onActivityPostStarted(activity) + assertTrue(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + } + + @Test + fun `When firstActivityCreated is false and app start span has stopped, restart app start to current date`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + val appStartDate = SentryNanotimeDate(Date(1), 0) + val appStartMetrics = AppStartMetrics.getInstance() + val activity = mock() + setAppStartTime(appStartDate) + // Let's pretend app start started and finished + appStartMetrics.appStartTimeSpan.stop() + sut.register(fixture.hub, fixture.options) + + assertEquals(0, sut.getProperty("lastPausedUptimeMillis")) + + // An Activity (the first) is created after app start has finished + sut.onActivityPreCreated(activity, null) + // lastPausedUptimeMillis is set to current SystemClock.uptimeMillis() + val lastUptimeMillis = sut.getProperty("lastPausedUptimeMillis") + assertNotEquals(0, lastUptimeMillis) + + sut.onActivityCreated(activity, null) + // AppStartMetrics app start time is set to Activity preCreated timestamp + assertEquals(lastUptimeMillis, appStartMetrics.appStartTimeSpan.startUptimeMs) + // AppStart type is considered warm + assertEquals(AppStartType.WARM, appStartMetrics.appStartType) + + // Activity appStart span timestamp is the same of AppStartMetrics.appStart timestamp + assertEquals(sut.appStartSpan!!.startDate.nanoTimestamp(), appStartMetrics.getAppStartTimeSpanWithFallback(fixture.options).startTimestamp!!.nanoTimestamp()) + } + + private fun SentryTracer.isFinishing() = getProperty("finishStatus").getProperty("isFinishing") + private fun runFirstDraw(view: View) { // Removes OnDrawListener in the next OnGlobalLayout after onDraw view.viewTreeObserver.dispatchOnDraw() 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 23ab5a3bc8..35e0f5257b 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 @@ -13,6 +13,7 @@ import io.sentry.SpanStatus import io.sentry.TracesSamplingDecision import io.sentry.TransactionContext import io.sentry.android.core.ActivityLifecycleIntegration.APP_START_COLD +import io.sentry.android.core.ActivityLifecycleIntegration.APP_START_WARM import io.sentry.android.core.ActivityLifecycleIntegration.UI_LOAD_OP import io.sentry.android.core.performance.ActivityLifecycleTimeSpan import io.sentry.android.core.performance.AppStartMetrics @@ -59,13 +60,13 @@ class PerformanceAndroidEventProcessorTest { private val fixture = Fixture() - private fun createAppStartSpan(traceId: SentryId) = SentrySpan( + private fun createAppStartSpan(traceId: SentryId, coldStart: Boolean = true) = SentrySpan( 0.0, 1.0, traceId, SpanId(), null, - APP_START_COLD, + if (coldStart) APP_START_COLD else APP_START_WARM, "App Start", SpanStatus.OK, null, @@ -292,6 +293,56 @@ class PerformanceAndroidEventProcessorTest { ) } + @Test + fun `adds app start metrics to app warm start txn`() { + // given some app start metrics + val appStartMetrics = AppStartMetrics.getInstance() + appStartMetrics.appStartType = AppStartType.WARM + 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.warm span + val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId, false) + tr.spans.add(appStartSpan) + + // then the app start metrics should be attached + tr = sut.process(tr, Hint()) + + // process init, content provider and application span should not be attached + assertFalse(tr.spans.any { "process.load" == it.op }) + assertFalse(tr.spans.any { "contentprovider.load" == it.op }) + assertFalse(tr.spans.any { "application.load" == it.op }) + + // activity spans should be attached + assertTrue(tr.spans.any { "activity.load" == it.op && "MainActivity.onCreate" == it.description }) + assertTrue(tr.spans.any { "activity.load" == it.op && "MainActivity.onStart" == it.description }) + } + @Test fun `when app launched from background, app start spans are dropped`() { // given some app start metrics @@ -444,8 +495,10 @@ class PerformanceAndroidEventProcessorTest { val appStartSpan = createAppStartSpan(tr.contexts.trace!!.traceId) tr.spans.add(appStartSpan) - // then the app start metrics should not be attached + assertTrue(appStartMetrics.shouldSendStartMeasurements()) + // then the app start metrics should be attached tr = sut.process(tr, Hint()) + assertFalse(appStartMetrics.shouldSendStartMeasurements()) assertTrue( tr.spans.any { 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 ff6a299bed..9f868d701b 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 @@ -3,7 +3,6 @@ package io.sentry.android.core import android.app.Application import android.content.pm.ProviderInfo import android.os.Build -import android.os.Bundle import androidx.test.ext.junit.runners.AndroidJUnit4 import io.sentry.ILogger import io.sentry.JsonSerializer @@ -12,7 +11,6 @@ import io.sentry.SentryAppStartProfilingOptions import io.sentry.SentryLevel import io.sentry.SentryOptions import io.sentry.android.core.performance.AppStartMetrics -import io.sentry.android.core.performance.AppStartMetrics.AppStartType import org.junit.runner.RunWith import org.mockito.kotlin.any import org.mockito.kotlin.eq @@ -28,7 +26,6 @@ import java.nio.file.Files import kotlin.test.AfterTest import kotlin.test.BeforeTest import kotlin.test.Test -import kotlin.test.assertEquals import kotlin.test.assertFailsWith import kotlin.test.assertFalse import kotlin.test.assertNotNull @@ -104,50 +101,6 @@ class SentryPerformanceProviderTest { assertTrue(AppStartMetrics.getInstance().appStartTimeSpan.hasStarted()) } - @Test - fun `provider sets cold start based on first activity`() { - val provider = fixture.getSut() - - // up until this point app start is not known - assertEquals(AppStartType.UNKNOWN, AppStartMetrics.getInstance().appStartType) - - // when there's no saved state - provider.activityCallback!!.onActivityCreated(mock(), null) - // then app start should be cold - assertEquals(AppStartType.COLD, AppStartMetrics.getInstance().appStartType) - } - - @Test - fun `provider sets warm start based on first activity`() { - val provider = fixture.getSut() - - // up until this point app start is not known - assertEquals(AppStartType.UNKNOWN, AppStartMetrics.getInstance().appStartType) - - // when there's a saved state - provider.activityCallback!!.onActivityCreated(mock(), Bundle()) - - // then app start should be warm - assertEquals(AppStartType.WARM, AppStartMetrics.getInstance().appStartType) - } - - @Test - fun `provider keeps startup state even if multiple activities are launched`() { - val provider = fixture.getSut() - - // when there's a saved state - provider.activityCallback!!.onActivityCreated(mock(), Bundle()) - - // then app start should be warm - assertEquals(AppStartType.WARM, AppStartMetrics.getInstance().appStartType) - - // when another activity is launched cold - provider.activityCallback!!.onActivityCreated(mock(), null) - - // then app start should remain warm - assertEquals(AppStartType.WARM, AppStartMetrics.getInstance().appStartType) - } - @Test fun `provider sets both appstart and sdk init start + end times`() { val provider = fixture.getSut() 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 eb0e85dc28..d8b9e727e2 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 @@ -276,4 +276,50 @@ class AppStartMetricsTest { Shadows.shadowOf(Looper.getMainLooper()).idle() assertTrue(AppStartMetrics.getInstance().isAppLaunchedInForeground) } + + @Test + fun `isColdStartValid is false if app was launched in background`() { + AppStartMetrics.getInstance().isAppLaunchedInForeground = false + assertFalse(AppStartMetrics.getInstance().isColdStartValid) + } + + @Test + fun `isColdStartValid is false if app launched in more than 1 minute`() { + val appStartTimeSpan = AppStartMetrics.getInstance().appStartTimeSpan + appStartTimeSpan.start() + appStartTimeSpan.stop() + appStartTimeSpan.setStartedAt(1) + appStartTimeSpan.setStoppedAt(TimeUnit.MINUTES.toMillis(1) + 2) + AppStartMetrics.getInstance().onActivityCreated(mock(), mock()) + assertFalse(AppStartMetrics.getInstance().isColdStartValid) + } + + @Test + fun `onAppStartSpansSent set measurement flag and clear internal lists`() { + val appStartMetrics = AppStartMetrics.getInstance() + appStartMetrics.addActivityLifecycleTimeSpans(mock()) + appStartMetrics.contentProviderOnCreateTimeSpans.add(mock()) + assertTrue(appStartMetrics.shouldSendStartMeasurements()) + appStartMetrics.onAppStartSpansSent() + assertTrue(appStartMetrics.activityLifecycleTimeSpans.isEmpty()) + assertTrue(appStartMetrics.contentProviderOnCreateTimeSpans.isEmpty()) + assertFalse(appStartMetrics.shouldSendStartMeasurements()) + } + + @Test + fun `restartAppStart set measurement flag and clear internal lists`() { + val appStartMetrics = AppStartMetrics.getInstance() + appStartMetrics.onAppStartSpansSent() + appStartMetrics.isAppLaunchedInForeground = false + assertFalse(appStartMetrics.shouldSendStartMeasurements()) + assertFalse(appStartMetrics.isColdStartValid) + + appStartMetrics.restartAppStart(10) + + assertTrue(appStartMetrics.shouldSendStartMeasurements()) + assertTrue(appStartMetrics.isColdStartValid) + assertTrue(appStartMetrics.appStartTimeSpan.hasStarted()) + assertTrue(appStartMetrics.appStartTimeSpan.hasNotStopped()) + assertEquals(10, appStartMetrics.appStartTimeSpan.startUptimeMs) + } }