Trim time-to-full-display span if reportFullyDisplayed API is never c…

…alled (#2631)

* ttfd span is trimmed if `reportFullyDisplayed` API is never called
* exposed `getFinishDate` internally in ISpan

CHANGELOG.md

@@ -13,6 +13,7 @@
 
 ### Fixes
 
+- Trim time-to-full-display span if reportFullyDisplayed API is never called ([#2631](https://github.com/getsentry/sentry-java/pull/2631))
 - Fix Automatic UI transactions having wrong durations ([#2623](https://github.com/getsentry/sentry-java/pull/2623))
 - Fix wrong default environment in Session ([#2610](https://github.com/getsentry/sentry-java/pull/2610))
 - Pass through unknown sentry baggage keys into SentryEnvelopeHeader ([#2618](https://github.com/getsentry/sentry-java/pull/2618))

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

@@ -253,7 +253,7 @@ private void startTracing(final @NotNull Activity activity) {
             options
                 .getExecutorService()
                 .schedule(
-                    () -> finishSpan(ttfdSpan, SpanStatus.DEADLINE_EXCEEDED), TTFD_TIMEOUT_MILLIS);
+                    () -> finishExceededTtfdSpan(ttidSpanMap.get(activity)), TTFD_TIMEOUT_MILLIS);
       }
 
       // lets bind to the scope so other integrations can pick it up
@@ -320,7 +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) {
-        finishSpan(ttfdSpan, SpanStatus.DEADLINE_EXCEEDED);
+        finishExceededTtfdSpan(ttidSpan);
       }
       cancelTtfdAutoClose();
 
@@ -449,8 +449,8 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) {
     final ISpan ttidSpan = ttidSpanMap.get(activity);
     finishSpan(ttidSpan, SpanStatus.DEADLINE_EXCEEDED);
 
-    // we finish the ttfdSpan as cancelled in case it isn't completed yet
-    finishSpan(ttfdSpan, SpanStatus.DEADLINE_EXCEEDED);
+    // we finish the ttfdSpan as deadline_exceeded in case it isn't completed yet
+    finishExceededTtfdSpan(ttidSpan);
     cancelTtfdAutoClose();
 
     // in case people opt-out enableActivityLifecycleTracingAutoFinish and forgot to finish it,
@@ -477,9 +477,18 @@ private void finishSpan(final @Nullable ISpan span) {
   }
 
   private void finishSpan(final @Nullable ISpan span, final @NotNull SentryDate endTimestamp) {
+    finishSpan(span, endTimestamp, null);
+  }
+
+  private void finishSpan(
+      final @Nullable ISpan span,
+      final @NotNull SentryDate endTimestamp,
+      final @Nullable SpanStatus spanStatus) {
     if (span != null && !span.isFinished()) {
       final @NotNull SpanStatus status =
-          span.getStatus() != null ? span.getStatus() : SpanStatus.OK;
+          spanStatus != null
+              ? spanStatus
+              : span.getStatus() != null ? span.getStatus() : SpanStatus.OK;
       span.finish(status, endTimestamp);
     }
   }
@@ -531,6 +540,18 @@ private void onFullFrameDrawn() {
     cancelTtfdAutoClose();
   }
 
+  private void finishExceededTtfdSpan(final @Nullable ISpan ttidSpan) {
+    if (ttfdSpan == null) {
+      return;
+    }
+    ttfdSpan.setDescription(getExceededTtfdDesc(ttfdSpan));
+    // We set the end timestamp of the ttfd span to be equal to the ttid span. This way,
+    final @Nullable SentryDate ttidEndDate = ttidSpan != null ? ttidSpan.getFinishDate() : null;
+    final @NotNull SentryDate ttfdEndDate =
+        ttidEndDate != null ? ttidEndDate : ttfdSpan.getStartDate();
+    finishSpan(ttfdSpan, ttfdEndDate, SpanStatus.DEADLINE_EXCEEDED);
+  }
+
   @TestOnly
   @NotNull
   WeakHashMap<Activity, ITransaction> getActivitiesWithOngoingTransactions() {
@@ -577,6 +598,13 @@ private void setColdStart(final @Nullable Bundle savedInstanceState) {
     return activityName + " full display";
   }
 
+  private @NotNull String getExceededTtfdDesc(final @NotNull ISpan ttfdSpan) {
+    final @Nullable String ttfdCurrentDescription = ttfdSpan.getDescription();
+    if (ttfdCurrentDescription != null && ttfdCurrentDescription.endsWith(" - Deadline Exceeded"))
+      return ttfdCurrentDescription;
+    return ttfdSpan.getDescription() + " - Deadline Exceeded";
+  }
+
   private @NotNull String getAppStartDesc(final boolean coldStart) {
     if (coldStart) {
       return "Cold Start";

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

@@ -1307,6 +1307,51 @@ class ActivityLifecycleIntegrationTest {
         assertEquals(sut.ttfdSpan?.startDate, fixture.transaction.startDate)
     }
 
+    @Test
+    fun `ttfd span is trimmed if reportFullyDisplayed is never called`() {
+        val sut = fixture.getSut()
+        val activity = mock<Activity>()
+        val view = fixture.createView()
+        var lastScheduledRunnable: Runnable? = null
+        val mockExecutorService = object : ISentryExecutorService {
+            override fun submit(runnable: Runnable): Future<*> = mock()
+            override fun <T> submit(callable: Callable<T>): Future<T> = mock()
+            override fun schedule(runnable: Runnable, delayMillis: Long): Future<*> {
+                lastScheduledRunnable = runnable
+                return FutureTask {}
+            }
+            override fun close(timeoutMillis: Long) {}
+        }
+        fixture.options.tracesSampleRate = 1.0
+        fixture.options.isEnableTimeToFullDisplayTracing = true
+        fixture.options.executorService = mockExecutorService
+        sut.register(fixture.hub, fixture.options)
+        sut.onActivityCreated(activity, fixture.bundle)
+        sut.onActivityResumed(activity)
+
+        runFirstDraw(view)
+        val ttidSpan = sut.ttidSpanMap[activity]
+        val ttfdSpan = sut.ttfdSpan
+
+        // The ttid should be finished
+        assertNotNull(ttidSpan)
+        assertTrue(ttidSpan.isFinished)
+
+        // Assert the ttfd span is still running
+        assertNotNull(ttfdSpan)
+        assertFalse(ttfdSpan.isFinished)
+
+        // Run the autoClose task 1 ms after finishing the ttid span and assert the ttfd span is finished
+        Thread.sleep(1)
+        lastScheduledRunnable!!.run()
+        assertTrue(ttfdSpan.isFinished)
+
+        // the ttfd span should be trimmed to be equal to the ttid span, and the description should end with "-exceeded"
+        assertEquals(SpanStatus.DEADLINE_EXCEEDED, ttfdSpan.status)
+        assertEquals(ttidSpan.finishDate, ttfdSpan.finishDate)
+        assertEquals(ttfdSpan.description, "Activity full display - Deadline Exceeded")
+    }
+
     private fun runFirstDraw(view: View) {
         // Removes OnDrawListener in the next OnGlobalLayout after onDraw
         view.viewTreeObserver.dispatchOnDraw()

sentry/api/sentry.api

@@ -549,6 +549,7 @@ public abstract interface class io/sentry/ISpan {
 	public abstract fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V
 	public abstract fun getData (Ljava/lang/String;)Ljava/lang/Object;
 	public abstract fun getDescription ()Ljava/lang/String;
+	public abstract fun getFinishDate ()Lio/sentry/SentryDate;
 	public abstract fun getOperation ()Ljava/lang/String;
 	public abstract fun getSpanContext ()Lio/sentry/SpanContext;
 	public abstract fun getStartDate ()Lio/sentry/SentryDate;
@@ -820,6 +821,7 @@ public final class io/sentry/NoOpSpan : io/sentry/ISpan {
 	public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V
 	public fun getData (Ljava/lang/String;)Ljava/lang/Object;
 	public fun getDescription ()Ljava/lang/String;
+	public fun getFinishDate ()Lio/sentry/SentryDate;
 	public static fun getInstance ()Lio/sentry/NoOpSpan;
 	public fun getOperation ()Ljava/lang/String;
 	public fun getSpanContext ()Lio/sentry/SpanContext;
@@ -856,6 +858,7 @@ public final class io/sentry/NoOpTransaction : io/sentry/ITransaction {
 	public fun getData (Ljava/lang/String;)Ljava/lang/Object;
 	public fun getDescription ()Ljava/lang/String;
 	public fun getEventId ()Lio/sentry/protocol/SentryId;
+	public fun getFinishDate ()Lio/sentry/SentryDate;
 	public static fun getInstance ()Lio/sentry/NoOpTransaction;
 	public fun getLatestActiveSpan ()Lio/sentry/Span;
 	public fun getName ()Ljava/lang/String;

sentry/src/main/java/io/sentry/ISpan.java

@@ -238,6 +238,15 @@ ISpan startChild(
   @NotNull
   SentryDate getStartDate();
 
+  /**
+   * Returns the end date of this span or transaction.
+   *
+   * @return the end date
+   */
+  @ApiStatus.Internal
+  @Nullable
+  SentryDate getFinishDate();
+
   /**
    * Whether this span instance is a NOOP that doesn't collect information
    *

sentry/src/main/java/io/sentry/NoOpSpan.java

@@ -150,6 +150,11 @@ public boolean updateEndDate(final @NotNull SentryDate date) {
     return new SentryNanotimeDate();
   }
 
+  @Override
+  public @NotNull SentryDate getFinishDate() {
+    return new SentryNanotimeDate();
+  }
+
   @Override
   public boolean isNoOp() {
     return true;

sentry/src/main/java/io/sentry/NoOpTransaction.java

@@ -214,6 +214,11 @@ public boolean updateEndDate(final @NotNull SentryDate date) {
     return new SentryNanotimeDate();
   }
 
+  @Override
+  public @NotNull SentryDate getFinishDate() {
+    return new SentryNanotimeDate();
+  }
+
   @Override
   public boolean isNoOp() {
     return true;

sentry/src/main/java/io/sentry/SentryTracer.java

@@ -146,6 +146,7 @@ private void cancelTimer() {
     return this.root.getStartDate();
   }
 
+  @Override
   public @Nullable SentryDate getFinishDate() {
     return this.root.getFinishDate();
   }

sentry/src/main/java/io/sentry/Span.java

@@ -97,6 +97,7 @@ public Span(
     return startTimestamp;
   }
 
+  @Override
   public @Nullable SentryDate getFinishDate() {
     return timestamp;
   }

sentry/src/test/java/io/sentry/NoOpSpanTest.kt

@@ -35,4 +35,9 @@ class NoOpSpanTest {
     fun `startDate return a NanotimeDate`() {
         assertIs<SentryNanotimeDate>(span.startDate)
     }
+
+    @Test
+    fun `finishDate return a NanotimeDate`() {
+        assertIs<SentryNanotimeDate>(span.finishDate)
+    }
 }

sentry/src/test/java/io/sentry/NoOpTransactionTest.kt

@@ -41,4 +41,9 @@ class NoOpTransactionTest {
     fun `startDate return a NanotimeDate`() {
         assertIs<SentryNanotimeDate>(transaction.startDate)
     }
+
+    @Test
+    fun `finishDate return a NanotimeDate`() {
+        assertIs<SentryNanotimeDate>(transaction.finishDate)
+    }
 }