fix(android): Anchor the frame-metrics time projection (JAVA-579)

CHANGELOG.md

@@ -1,5 +1,11 @@
 # Changelog
 
+## Unreleased
+
+### Fixes
+
+- Place wall-clock-stamped spans, such as app start spans, on the frame timeline using a fixed anchor, so that a device time change or time spent suspended no longer shifts the frame data attributed to them ([#6098](https://github.com/getsentry/sentry-java/pull/6098))
+
 ## 8.56.0
 
 ### Behavioral Changes

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

@@ -1,6 +1,5 @@
 package io.sentry.android.core;
 
-import io.sentry.DateUtils;
 import io.sentry.IPerformanceContinuousCollector;
 import io.sentry.ISentryLifecycleToken;
 import io.sentry.ISpan;
@@ -12,6 +11,10 @@
 import io.sentry.SpanDataConvention;
 import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
 import io.sentry.protocol.MeasurementValue;
+import io.sentry.time.EpochClock;
+import io.sentry.time.JavaMonotonicTicker;
+import io.sentry.time.MonotonicTicker;
+import io.sentry.time.SystemEpochClock;
 import io.sentry.util.AutoClosableReentrantLock;
 import java.util.Iterator;
 import java.util.SortedSet;
@@ -68,12 +71,35 @@ public class SpanFrameMetricsCollector
   // assume 60fps until we get a value reported by the system
   private long lastKnownFrameDurationNanos = 16_666_666L;
 
+  // One wall-clock reading paired with one tick, both taken at construction, used to place
+  // wall-stamped span dates on the frame timeline. See toNanoTime.
+  private final long wallAnchorNanos;
+  private final long tickAnchorNanos;
+
   public SpanFrameMetricsCollector(
       final @NotNull SentryAndroidOptions options,
       final @NotNull SentryFrameMetricsCollector frameMetricsCollector) {
+    // Deliberately not options.getMonotonicTicker(), which is elapsedRealtimeNanos on Android:
+    // frames are stamped by Choreographer on System.nanoTime(), and the two bases drift apart by
+    // however long the device spends suspended.
+    this(
+        options,
+        frameMetricsCollector,
+        SystemEpochClock.getInstance(),
+        JavaMonotonicTicker.getInstance());
+  }
+
+  SpanFrameMetricsCollector(
+      final @NotNull SentryAndroidOptions options,
+      final @NotNull SentryFrameMetricsCollector frameMetricsCollector,
+      final @NotNull EpochClock epochClock,
+      final @NotNull MonotonicTicker frameTicker) {
     this.frameMetricsCollector = frameMetricsCollector;
 
     enabled = options.isEnablePerformanceV2() && options.isEnableFramesTracking();
+
+    this.wallAnchorNanos = epochClock.now().epochNanos();
+    this.tickAnchorNanos = frameTicker.tickNanos();
   }
 
   @Override
@@ -312,18 +338,22 @@ private static int addPendingFrameDelay(
    * @param date the input date
    * @return a non-unix timestamp in nano precision, similar to {@link System#nanoTime()}.
    */
-  private static long toNanoTime(final @NotNull SentryDate date) {
+  private long toNanoTime(final @NotNull SentryDate date) {
     // SentryNanotimeDate nanotime is based on System.nanotime(), like EMPTY_NANO_TIME,
     // thus diff will simply return the System.nanotime() value of date
     if (date instanceof SentryNanotimeDate) {
       return date.diff(EMPTY_NANO_TIME);
     }
 
-    // e.g. SentryLongDate is unix time based - upscaled to nanos,
-    // we need to project it back to System.nanotime() format
-    long nowUnixInNanos = DateUtils.millisToNanos(System.currentTimeMillis());
-    long shiftInNanos = nowUnixInNanos - date.nanoTimestamp();
-    return System.nanoTime() - shiftInNanos;
+    // e.g. SentryLongDate is unix time based - upscaled to nanos, so it has to be projected onto
+    // the frame timeline. That projection needs the offset between the two clocks, and the offset
+    // is only a constant while nothing disturbs either of them: a wall-clock step moves one, and
+    // time spent suspended moves the other, since System.nanoTime() stops in suspend and the wall
+    // clock does not. Reading the offset here, whenever a span happens to finish, would therefore
+    // charge the span for every step and every suspend since it started - an app start span can
+    // be projected hours away from the frames it actually overlapped. Hold the offset from
+    // construction instead, so a span lands where it did when the SDK started.
+    return tickAnchorNanos + (date.nanoTimestamp() - wallAnchorNanos);
   }
 
   private static class Frame implements Comparable<Frame> {

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

@@ -4,10 +4,15 @@ import io.sentry.ISpan
 import io.sentry.ITransaction
 import io.sentry.NoOpSpan
 import io.sentry.NoOpTransaction
+import io.sentry.SentryLongDate
 import io.sentry.SentryNanotimeDate
 import io.sentry.SpanContext
+import io.sentry.SpanDataConvention
 import io.sentry.android.core.internal.util.SentryFrameMetricsCollector
 import io.sentry.protocol.MeasurementValue
+import io.sentry.time.EpochClock
+import io.sentry.time.TestMonotonicTicker
+import io.sentry.time.Timestamp
 import java.util.UUID
 import java.util.concurrent.TimeUnit
 import kotlin.test.Test
@@ -84,6 +89,44 @@ class SpanFrameMetricsCollectorTest {
 
   private val fixture = Fixture()
 
+  @Test
+  fun `a wall-clock span is placed on the frame timeline using the anchor taken at construction`() {
+    // app start spans are SentryLongDates, stamped on the wall clock rather than on nanoTime
+    val anchorEpochNanos = TimeUnit.SECONDS.toNanos(1_600_000_000)
+    val frameTicker = TestMonotonicTicker()
+
+    whenever(fixture.frameMetricsCollector.startCollection(any()))
+      .thenReturn(UUID.randomUUID().toString())
+    whenever(fixture.frameMetricsCollector.getLastKnownFrameStartTimeNanos()).thenReturn(-1)
+    fixture.options.frameMetricsCollector = fixture.frameMetricsCollector
+    fixture.options.isEnableFramesTracking = true
+    fixture.options.isEnablePerformanceV2 = true
+
+    val sut =
+      SpanFrameMetricsCollector(
+        fixture.options,
+        fixture.frameMetricsCollector,
+        EpochClock { Timestamp.ofEpochNanos(anchorEpochNanos) },
+        frameTicker,
+      )
+
+    val span = mock<ISpan>()
+    whenever(span.spanContext).thenReturn(SpanContext("op.fake"))
+    whenever(span.startDate).thenReturn(SentryLongDate(anchorEpochNanos + 1_000))
+    whenever(span.finishDate).thenReturn(SentryLongDate(anchorEpochNanos + 100_000_000))
+
+    sut.onSpanStarted(span)
+    // one slow frame, on the frame timeline, fully inside the span
+    sut.onFrameMetricCollected(2_000, 50_000_000, 49_998_000, 30_000_000, true, false, 60.0f)
+
+    // the device spends an hour suspended before the span finishes, so the offset between the
+    // wall clock and the frame timeline is no longer what it was when the span started
+    frameTicker.advance(1, TimeUnit.HOURS)
+    sut.onSpanFinished(span)
+
+    verify(span).setData(SpanDataConvention.FRAMES_SLOW, 1)
+  }
+
   @Test
   fun `When AndroidSlowFrozenFrameCollector is initialized, it doesn't register any listener`() {
     fixture.getSut()