Report process init time for app start (#3159)

* Report process init time for app start * Rename op to process.load * Add Changelog * Ensure process init is only attached if it happened in the reasonable past
getsentry · Feb 12, 2024 · a537f8a · a537f8a
1 parent 749ed65
commit a537f8a
Show file tree

Hide file tree

Showing 6 changed files with 94 additions and 5 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -5,6 +5,7 @@
 ### Features
 
 - Add new threshold parameters to monitor config ([#3181](https://github.com/getsentry/sentry-java/pull/3181))
+- Report process init time as a span for app start performance ([#3159](https://github.com/getsentry/sentry-java/pull/3159))
 
 ## 7.3.0
 

diff --git a/sentry-android-core/api/sentry-android-core.api b/sentry-android-core/api/sentry-android-core.api
@@ -434,6 +434,7 @@ public class io/sentry/android/core/performance/AppStartMetrics {
 	public fun getAppStartTimeSpanWithFallback (Lio/sentry/android/core/SentryAndroidOptions;)Lio/sentry/android/core/performance/TimeSpan;
 	public fun getAppStartType ()Lio/sentry/android/core/performance/AppStartMetrics$AppStartType;
 	public fun getApplicationOnCreateTimeSpan ()Lio/sentry/android/core/performance/TimeSpan;
+	public fun getClassLoadedUptimeMs ()J
 	public fun getContentProviderOnCreateTimeSpans ()Ljava/util/List;
 	public static fun getInstance ()Lio/sentry/android/core/performance/AppStartMetrics;
 	public fun getSdkInitTimeSpan ()Lio/sentry/android/core/performance/TimeSpan;
@@ -445,6 +446,7 @@ public class io/sentry/android/core/performance/AppStartMetrics {
 	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 final class io/sentry/android/core/performance/AppStartMetrics$AppStartType : java/lang/Enum {

diff --git a/...y-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java b/...y-android-core/src/main/java/io/sentry/android/core/PerformanceAndroidEventProcessor.java
@@ -33,6 +33,8 @@ final class PerformanceAndroidEventProcessor implements EventProcessor {
   private static final String APP_METRICS_CONTENT_PROVIDER_OP = "contentprovider.load";
   private static final String APP_METRICS_ACTIVITIES_OP = "activity.load";
   private static final String APP_METRICS_APPLICATION_OP = "application.load";
+  private static final String APP_METRICS_PROCESS_INIT_OP = "process.load";
+  private static final long MAX_PROCESS_INIT_APP_START_DIFF_MS = 10000;
 
   private boolean sentStartMeasurement = false;
 
@@ -77,13 +79,13 @@ public SentryEvent process(@NotNull SentryEvent event, @NotNull Hint hint) {
     if (!sentStartMeasurement && hasAppStartSpan(transaction)) {
       final @NotNull TimeSpan appStartTimeSpan =
           AppStartMetrics.getInstance().getAppStartTimeSpanWithFallback(options);
-      final long appStartUpInterval = appStartTimeSpan.getDurationMs();
+      final long appStartUpDurationMs = appStartTimeSpan.getDurationMs();
 
-      // if appStartUpInterval is 0, metrics are not ready to be sent
-      if (appStartUpInterval != 0) {
+      // if appStartUpDurationMs is 0, metrics are not ready to be sent
+      if (appStartUpDurationMs != 0) {
         final MeasurementValue value =
             new MeasurementValue(
-                (float) appStartUpInterval, MeasurementUnit.Duration.MILLISECOND.apiName());
+                (float) appStartUpDurationMs, MeasurementUnit.Duration.MILLISECOND.apiName());
 
         final String appStartKey =
             AppStartMetrics.getInstance().getAppStartType() == AppStartMetrics.AppStartType.COLD
@@ -155,6 +157,25 @@ private void attachColdAppStartSpans(
       }
     }
 
+    // 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));
+    }
+
     // Content Providers
     final @NotNull List<TimeSpan> contentProviderOnCreates =
         appStartMetrics.getContentProviderOnCreateTimeSpans();

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
@@ -31,6 +31,8 @@ public enum AppStartType {
     WARM
   }
 
+  private static long CLASS_LOADED_UPTIME_MS = SystemClock.uptimeMillis();
+
   private static volatile @Nullable AppStartMetrics instance;
 
   private @NotNull AppStartType appStartType = AppStartType.UNKNOWN;
@@ -121,6 +123,10 @@ public void addActivityLifecycleTimeSpans(final @NotNull ActivityLifecycleTimeSp
     activityLifecycles.add(timeSpan);
   }
 
+  public long getClassLoadedUptimeMs() {
+    return CLASS_LOADED_UPTIME_MS;
+  }
+
   /**
    * @return the app start time span if it was started and perf-2 is enabled, falls back to the sdk
    *     init time span otherwise
@@ -171,6 +177,12 @@ public void setAppStartSamplingDecision(
     return appStartSamplingDecision;
   }
 
+  @TestOnly
+  @ApiStatus.Internal
+  public void setClassLoadedUptimeMs(final long classLoadedUptimeMs) {
+    CLASS_LOADED_UPTIME_MS = classLoadedUptimeMs;
+  }
+
   /**
    * Called by instrumentation
    *

diff --git a/...android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt b/...android-core/src/test/java/io/sentry/android/core/PerformanceAndroidEventProcessorTest.kt
@@ -246,6 +246,13 @@ class PerformanceAndroidEventProcessorTest {
         // then the app start metrics should be attached
         tr = sut.process(tr, Hint())
 
+        assertTrue(
+            tr.spans.any {
+                "process.load" == it.op &&
+                    appStartSpan.spanId == it.parentSpanId
+            }
+        )
+
         assertTrue(
             tr.spans.any {
                 "contentprovider.load" == it.op &&
@@ -300,7 +307,7 @@ class PerformanceAndroidEventProcessorTest {
 
     @Test
     fun `does not add app start metrics more than once`() {
-        // given some WARM app start metrics
+        // given some cold app start metrics
         val appStartMetrics = AppStartMetrics.getInstance()
         appStartMetrics.appStartType = AppStartType.COLD
         appStartMetrics.appStartTimeSpan.setStartedAt(123)
@@ -351,6 +358,46 @@ class PerformanceAndroidEventProcessorTest {
         )
     }
 
+    @Test
+    fun `does not add process init span if it happened too early`() {
+        // given some cold app start metrics
+        // where class loaded happened way before app start
+        val appStartMetrics = AppStartMetrics.getInstance()
+        appStartMetrics.appStartType = AppStartType.COLD
+        appStartMetrics.appStartTimeSpan.setStartedAt(11001)
+        appStartMetrics.appStartTimeSpan.setStoppedAt(12000)
+        appStartMetrics.classLoadedUptimeMs = 1000
+
+        val sut = fixture.getSut(enablePerformanceV2 = true)
+        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(),
+            null
+        )
+        tr.spans.add(appStartSpan)
+
+        // when the processor attaches the app start spans
+        tr = sut.process(tr, Hint())
+
+        // process load should not be included
+        assertFalse(
+            tr.spans.any {
+                "process.load" == it.op
+            }
+        )
+    }
+
     private fun setAppStart(options: SentryAndroidOptions, coldStart: Boolean = true) {
         AppStartMetrics.getInstance().apply {
             appStartType = when (coldStart) {

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
@@ -12,6 +12,7 @@ import org.mockito.kotlin.mock
 import org.robolectric.annotation.Config
 import kotlin.test.Test
 import kotlin.test.assertEquals
+import kotlin.test.assertNotEquals
 import kotlin.test.assertNull
 import kotlin.test.assertSame
 import kotlin.test.assertTrue
@@ -100,4 +101,9 @@ class AppStartMetricsTest {
         val sdkInitSpan = AppStartMetrics.getInstance().sdkInitTimeSpan
         assertSame(sdkInitSpan, timeSpan)
     }
+
+    @Test
+    fun `class load time is set`() {
+        assertNotEquals(0, AppStartMetrics.getInstance().classLoadedUptimeMs)
+    }
 }