Track a ttfd span per Activity (#2673)

* added map of ttfd spans in ActivityLifecycleIntegration, to automatically stop only the correct one

CHANGELOG.md

@@ -1,5 +1,11 @@
 # Changelog
 
+## Unreleased
+
+### Fixes
+
+- Track a ttfd span per Activity ([#2673](https://github.com/getsentry/sentry-java/pull/2673))
+
 ## 6.18.0
 
 ### Features

sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java

@@ -70,9 +70,9 @@ public final class ActivityLifecycleIntegration
   private @Nullable FullyDisplayedReporter fullyDisplayedReporter = null;
   private @Nullable ISpan appStartSpan;
   private final @NotNull WeakHashMap<Activity, ISpan> ttidSpanMap = new WeakHashMap<>();
+  private final @NotNull WeakHashMap<Activity, ISpan> ttfdSpanMap = new WeakHashMap<>();
   private @NotNull SentryDate lastPausedTime = AndroidDateUtils.getCurrentSentryDateTime();
   private final @NotNull Handler mainHandler = new Handler(Looper.getMainLooper());
-  private @Nullable ISpan ttfdSpan = null;
   private @Nullable Future<?> ttfdAutoCloseFuture = null;
 
   // WeakHashMap isn't thread safe but ActivityLifecycleCallbacks is only called from the
@@ -168,7 +168,8 @@ private void stopPreviousTransactions() {
         activitiesWithOngoingTransactions.entrySet()) {
       final ITransaction transaction = entry.getValue();
       final ISpan ttidSpan = ttidSpanMap.get(entry.getKey());
-      finishTransaction(transaction, ttidSpan, true);
+      final ISpan ttfdSpan = ttfdSpanMap.get(entry.getKey());
+      finishTransaction(transaction, ttidSpan, ttfdSpan);
     }
   }
 
@@ -240,20 +241,20 @@ private void startTracing(final @NotNull Activity activity) {
         // we can finish the app-start span
         finishAppStartSpan();
       }
-      ttidSpanMap.put(
-          activity,
+      final @NotNull ISpan ttidSpan =
           transaction.startChild(
-              TTID_OP, getTtidDesc(activityName), ttidStartTime, Instrumenter.SENTRY));
+              TTID_OP, getTtidDesc(activityName), ttidStartTime, Instrumenter.SENTRY);
+      ttidSpanMap.put(activity, ttidSpan);
 
       if (timeToFullDisplaySpanEnabled && fullyDisplayedReporter != null && options != null) {
-        ttfdSpan =
+        final @NotNull ISpan ttfdSpan =
             transaction.startChild(
                 TTFD_OP, getTtfdDesc(activityName), ttidStartTime, Instrumenter.SENTRY);
+        ttfdSpanMap.put(activity, ttfdSpan);
         ttfdAutoCloseFuture =
             options
                 .getExecutorService()
-                .schedule(
-                    () -> finishExceededTtfdSpan(ttidSpanMap.get(activity)), TTFD_TIMEOUT_MILLIS);
+                .schedule(() -> finishExceededTtfdSpan(ttfdSpan, ttidSpan), TTFD_TIMEOUT_MILLIS);
       }
 
       // lets bind to the scope so other integrations can pick it up
@@ -302,14 +303,14 @@ private boolean isRunningTransaction(final @NotNull Activity activity) {
   private void stopTracing(final @NotNull Activity activity, final boolean shouldFinishTracing) {
     if (performanceEnabled && shouldFinishTracing) {
       final ITransaction transaction = activitiesWithOngoingTransactions.get(activity);
-      finishTransaction(transaction, null, false);
+      finishTransaction(transaction, null, null);
     }
   }
 
   private void finishTransaction(
       final @Nullable ITransaction transaction,
       final @Nullable ISpan ttidSpan,
-      final boolean finishTtfd) {
+      final @Nullable ISpan ttfdSpan) {
     if (transaction != null) {
       // if io.sentry.traces.activity.auto-finish.enable is disabled, transaction may be already
       // finished manually when this method is called.
@@ -319,9 +320,7 @@ private void finishTransaction(
 
       // in case the ttidSpan isn't completed yet, we finish it as cancelled to avoid memory leak
       finishSpan(ttidSpan, SpanStatus.DEADLINE_EXCEEDED);
-      if (finishTtfd) {
-        finishExceededTtfdSpan(ttidSpan);
-      }
+      finishExceededTtfdSpan(ttfdSpan, ttidSpan);
       cancelTtfdAutoClose();
 
       SpanStatus status = transaction.getStatus();
@@ -347,11 +346,12 @@ public synchronized void onActivityCreated(
     setColdStart(savedInstanceState);
     addBreadcrumb(activity, "created");
     startTracing(activity);
+    final @Nullable ISpan ttfdSpan = ttfdSpanMap.get(activity);
 
     firstActivityCreated = true;
 
     if (fullyDisplayedReporter != null) {
-      fullyDisplayedReporter.registerFullyDrawnListener(() -> onFullFrameDrawn());
+      fullyDisplayedReporter.registerFullyDrawnListener(() -> onFullFrameDrawn(ttfdSpan));
     }
   }
 
@@ -382,16 +382,17 @@ public synchronized void onActivityResumed(final @NotNull Activity activity) {
     }
     finishAppStartSpan();
 
-    final ISpan ttidSpan = ttidSpanMap.get(activity);
+    final @Nullable ISpan ttidSpan = ttidSpanMap.get(activity);
+    final @Nullable ISpan ttfdSpan = ttfdSpanMap.get(activity);
     final View rootView = activity.findViewById(android.R.id.content);
     if (buildInfoProvider.getSdkInfoVersion() >= Build.VERSION_CODES.JELLY_BEAN
         && rootView != null) {
       FirstDrawDoneListener.registerForNextDraw(
-          rootView, () -> onFirstFrameDrawn(ttidSpan), buildInfoProvider);
+          rootView, () -> 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(ttidSpan));
+      mainHandler.post(() -> onFirstFrameDrawn(ttfdSpan, ttidSpan));
     }
     addBreadcrumb(activity, "resumed");
   }
@@ -447,10 +448,11 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) {
 
     // we finish the ttidSpan as cancelled in case it isn't completed yet
     final ISpan ttidSpan = ttidSpanMap.get(activity);
+    final ISpan ttfdSpan = ttfdSpanMap.get(activity);
     finishSpan(ttidSpan, SpanStatus.DEADLINE_EXCEEDED);
 
     // we finish the ttfdSpan as deadline_exceeded in case it isn't completed yet
-    finishExceededTtfdSpan(ttidSpan);
+    finishExceededTtfdSpan(ttfdSpan, ttidSpan);
     cancelTtfdAutoClose();
 
     // in case people opt-out enableActivityLifecycleTracingAutoFinish and forgot to finish it,
@@ -460,7 +462,7 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) {
     // set it to null in case its been just finished as cancelled
     appStartSpan = null;
     ttidSpanMap.remove(activity);
-    ttfdSpan = null;
+    ttfdSpanMap.remove(activity);
 
     // clear it up, so we don't start again for the same activity if the activity is in the activity
     // stack still.
@@ -506,7 +508,7 @@ private void cancelTtfdAutoClose() {
     }
   }
 
-  private void onFirstFrameDrawn(final @Nullable ISpan ttidSpan) {
+  private void onFirstFrameDrawn(final @Nullable ISpan ttfdSpan, final @Nullable ISpan ttidSpan) {
     if (options != null && ttidSpan != null) {
       final SentryDate endDate = options.getDateProvider().now();
       final long durationNanos = endDate.diff(ttidSpan.getStartDate());
@@ -526,7 +528,7 @@ private void onFirstFrameDrawn(final @Nullable ISpan ttidSpan) {
     }
   }
 
-  private void onFullFrameDrawn() {
+  private void onFullFrameDrawn(final @Nullable ISpan ttfdSpan) {
     if (options != null && ttfdSpan != null) {
       final SentryDate endDate = options.getDateProvider().now();
       final long durationNanos = endDate.diff(ttfdSpan.getStartDate());
@@ -540,12 +542,13 @@ private void onFullFrameDrawn() {
     cancelTtfdAutoClose();
   }
 
-  private void finishExceededTtfdSpan(final @Nullable ISpan ttidSpan) {
-    if (ttfdSpan == null) {
+  private void finishExceededTtfdSpan(
+      final @Nullable ISpan ttfdSpan, final @Nullable ISpan ttidSpan) {
+    if (ttfdSpan == null || ttfdSpan.isFinished()) {
       return;
     }
     ttfdSpan.setDescription(getExceededTtfdDesc(ttfdSpan));
-    // We set the end timestamp of the ttfd span to be equal to the ttid span. This way,
+    // We set the end timestamp of the ttfd span to be equal to the ttid span.
     final @Nullable SentryDate ttidEndDate = ttidSpan != null ? ttidSpan.getFinishDate() : null;
     final @NotNull SentryDate ttfdEndDate =
         ttidEndDate != null ? ttidEndDate : ttfdSpan.getStartDate();
@@ -577,9 +580,9 @@ WeakHashMap<Activity, ISpan> getTtidSpanMap() {
   }
 
   @TestOnly
-  @Nullable
-  ISpan getTtfdSpan() {
-    return ttfdSpan;
+  @NotNull
+  WeakHashMap<Activity, ISpan> getTtfdSpanMap() {
+    return ttfdSpanMap;
   }
 
   private void setColdStart(final @Nullable Bundle savedInstanceState) {

sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt

@@ -452,7 +452,7 @@ class ActivityLifecycleIntegrationTest {
         sut.onActivityCreated(activity, fixture.bundle)
 
         sut.ttidSpanMap.values.first().finish()
-        sut.ttfdSpan?.finish()
+        sut.ttfdSpanMap.values.first().finish()
 
         // then transaction should not be immediatelly finished
         verify(fixture.hub, never())
@@ -678,10 +678,10 @@ class ActivityLifecycleIntegrationTest {
 
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
-        assertNotNull(sut.ttfdSpan)
+        assertNotNull(sut.ttfdSpanMap[activity])
 
         sut.onActivityDestroyed(activity)
-        assertNull(sut.ttfdSpan)
+        assertNull(sut.ttfdSpanMap[activity])
     }
 
     @Test
@@ -719,7 +719,7 @@ class ActivityLifecycleIntegrationTest {
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, mock())
         sut.ttidSpanMap.values.first().finish()
-        sut.ttfdSpan?.finish()
+        sut.ttfdSpanMap.values.first().finish()
         sut.onActivityResumed(activity)
 
         verify(fixture.hub, never()).captureTransaction(any(), any(), anyOrNull(), anyOrNull())
@@ -748,7 +748,7 @@ class ActivityLifecycleIntegrationTest {
 
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, mock())
-        val ttfd = sut.ttfdSpan
+        val ttfd = sut.ttfdSpanMap[activity]
         sut.ttidSpanMap.values.first().finish()
         sut.onActivityResumed(activity)
         sut.onActivityPostResumed(activity)
@@ -766,10 +766,11 @@ class ActivityLifecycleIntegrationTest {
 
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, mock())
+        val ttfdSpan = sut.ttfdSpanMap[activity]
         sut.ttidSpanMap.values.first().finish()
         fixture.fullyDisplayedReporter.reportFullyDrawn()
-        assertTrue(sut.ttfdSpan!!.isFinished)
-        assertNotEquals(SpanStatus.CANCELLED, sut.ttfdSpan?.status)
+        assertTrue(ttfdSpan!!.isFinished)
+        assertNotEquals(SpanStatus.CANCELLED, ttfdSpan.status)
     }
 
     @Test
@@ -1070,7 +1071,8 @@ class ActivityLifecycleIntegrationTest {
 
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
-        assertNull(sut.ttfdSpan)
+        val ttfdSpan = sut.ttfdSpanMap[activity]
+        assertNull(ttfdSpan)
     }
 
     @Test
@@ -1082,7 +1084,8 @@ class ActivityLifecycleIntegrationTest {
 
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
-        assertNotNull(sut.ttfdSpan)
+        val ttfdSpan = sut.ttfdSpanMap[activity]
+        assertNotNull(ttfdSpan)
     }
 
     @Test
@@ -1104,7 +1107,7 @@ class ActivityLifecycleIntegrationTest {
         sut.register(fixture.hub, fixture.options)
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
-        val ttfdSpan = sut.ttfdSpan
+        val ttfdSpan = sut.ttfdSpanMap[activity]
 
         // Assert the ttfd span is running and a timeout autoCancel task has been scheduled
         assertNotNull(ttfdSpan)
@@ -1137,7 +1140,7 @@ class ActivityLifecycleIntegrationTest {
         sut.register(fixture.hub, fixture.options)
         val activity = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
-        val ttfdSpan = sut.ttfdSpan
+        val ttfdSpan = sut.ttfdSpanMap[activity]
         var autoCloseFuture = sut.getProperty<Future<*>?>("ttfdAutoCloseFuture")
 
         // Assert the ttfd span is running and a timeout autoCancel future has been scheduled
@@ -1180,7 +1183,7 @@ class ActivityLifecycleIntegrationTest {
         val activity2 = mock<Activity>()
         sut.onActivityCreated(activity, fixture.bundle)
         sut.onActivityPostResumed(activity)
-        val ttfdSpan = sut.ttfdSpan
+        val ttfdSpan = sut.ttfdSpanMap[activity]
         val autoCloseFuture = sut.getProperty<Future<*>?>("ttfdAutoCloseFuture")
 
         // Assert the ttfd span is running and a timeout autoCancel future has been scheduled
@@ -1196,7 +1199,7 @@ class ActivityLifecycleIntegrationTest {
 
         // Another autoClose future and ttfd span should be started after the second activity starts
         val autoCloseFuture2 = sut.getProperty<Future<*>?>("ttfdAutoCloseFuture")
-        val ttfdSpan2 = sut.ttfdSpan
+        val ttfdSpan2 = sut.ttfdSpanMap[activity2]
         assertNotNull(ttfdSpan2)
         assertFalse(ttfdSpan2.isFinished)
         assertNotNull(autoCloseFuture2)
@@ -1257,7 +1260,7 @@ class ActivityLifecycleIntegrationTest {
 
         // The ttid and ttfd spans should be running
         val ttidSpan = sut.ttidSpanMap[activity] as Span
-        val ttfdSpan = sut.ttfdSpan as Span
+        val ttfdSpan = sut.ttfdSpanMap[activity] as Span
         assertFalse(ttidSpan.isFinished)
         assertFalse(ttfdSpan.isFinished)
 
@@ -1301,10 +1304,12 @@ class ActivityLifecycleIntegrationTest {
 
         // The ttid span should be running
         val ttidSpan = sut.ttidSpanMap[activity]
+        val ttfdSpan = sut.ttfdSpanMap[activity]
         assertNotNull(ttidSpan)
+        assertNotNull(ttfdSpan)
 
         assertEquals(ttidSpan.startDate, fixture.transaction.startDate)
-        assertEquals(sut.ttfdSpan?.startDate, fixture.transaction.startDate)
+        assertEquals(ttfdSpan.startDate, fixture.transaction.startDate)
     }
 
     @Test
@@ -1331,7 +1336,7 @@ class ActivityLifecycleIntegrationTest {
 
         runFirstDraw(view)
         val ttidSpan = sut.ttidSpanMap[activity]
-        val ttfdSpan = sut.ttfdSpan
+        val ttfdSpan = sut.ttfdSpanMap[activity]
 
         // The ttid should be finished
         assertNotNull(ttidSpan)
@@ -1352,6 +1357,31 @@ class ActivityLifecycleIntegrationTest {
         assertEquals(ttfdSpan.description, "Activity full display - Deadline Exceeded")
     }
 
+    @Test
+    fun `ttfd span is running on new activity when previous finishes`() {
+        val sut = fixture.getSut()
+        val activity = mock<Activity>()
+        val activity2 = mock<Activity>()
+        fixture.options.tracesSampleRate = 1.0
+        fixture.options.isEnableTimeToFullDisplayTracing = true
+
+        sut.register(fixture.hub, fixture.options)
+        sut.onActivityCreated(activity, fixture.bundle)
+        val ttfdSpan = sut.ttfdSpanMap[activity]
+        assertNotNull(ttfdSpan)
+        assertFalse(ttfdSpan.isFinished)
+        sut.onActivityPaused(activity)
+        sut.onActivityCreated(activity2, fixture.bundle)
+        val ttfdSpan2 = sut.ttfdSpanMap[activity2]
+        sut.onActivityResumed(activity2)
+        sut.onActivityStopped(activity)
+        sut.onActivityDestroyed(activity)
+        assertNotNull(ttfdSpan2)
+        // The old ttfd is finished and the new one is running
+        assertTrue(ttfdSpan.isFinished)
+        assertFalse(ttfdSpan2.isFinished)
+    }
+
     private fun runFirstDraw(view: View) {
         // Removes OnDrawListener in the next OnGlobalLayout after onDraw
         view.viewTreeObserver.dispatchOnDraw()