[DO NOT MERGE] feat(time): Anchor span timestamps on one wall-clock reading (JAVA-572)

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

@@ -7,11 +7,11 @@
 import io.sentry.ITransaction;
 import io.sentry.NoOpSpan;
 import io.sentry.NoOpTransaction;
-import io.sentry.SentryDate;
-import io.sentry.SentryNanotimeDate;
 import io.sentry.SpanDataConvention;
 import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
 import io.sentry.protocol.MeasurementValue;
+import io.sentry.time.AnchoredClock;
+import io.sentry.time.Timestamp;
 import io.sentry.util.AutoClosableReentrantLock;
 import java.util.Iterator;
 import java.util.SortedSet;
@@ -32,7 +32,6 @@ public class SpanFrameMetricsCollector
   // grow indefinitely in case of a long running span
   private static final int MAX_FRAMES_COUNT = 3600;
   private static final long ONE_SECOND_NANOS = TimeUnit.SECONDS.toNanos(1);
-  private static final SentryNanotimeDate EMPTY_NANO_TIME = new SentryNanotimeDate(0, 0);
 
   private final boolean enabled;
   protected final @NotNull AutoClosableReentrantLock lock = new AutoClosableReentrantLock();
@@ -47,7 +46,8 @@ public class SpanFrameMetricsCollector
             if (o1 == o2) {
               return 0;
             }
-            int timeDiff = o1.getStartDate().compareTo(o2.getStartDate());
+            int timeDiff =
+                Long.compare(o1.startTimestamp().epochNanos(), o2.startTimestamp().epochNanos());
             if (timeDiff != 0) {
               return timeDiff;
             }
@@ -126,7 +126,7 @@ public void onSpanFinished(final @NotNull ISpan span) {
       } else {
         // otherwise only remove old/irrelevant frames
         final @NotNull ISpan oldestSpan = runningSpans.first();
-        frames.headSet(new Frame(toNanoTime(oldestSpan.getStartDate()))).clear();
+        frames.headSet(new Frame(toNanoTime(oldestSpan, oldestSpan.startTimestamp()))).clear();
       }
     }
   }
@@ -139,13 +139,13 @@ private void captureFrameMetrics(@NotNull final ISpan span) {
         return;
       }
 
-      final @Nullable SentryDate spanFinishDate = span.getFinishDate();
-      if (spanFinishDate == null) {
+      final @Nullable Timestamp spanFinish = span.endTimestamp();
+      if (spanFinish == null) {
         return;
       }
 
-      final long spanStartNanos = toNanoTime(span.getStartDate());
-      final long spanEndNanos = toNanoTime(spanFinishDate);
+      final long spanStartNanos = toNanoTime(span, span.startTimestamp());
+      final long spanEndNanos = toNanoTime(span, spanFinish);
       final long spanDurationNanos = spanEndNanos - spanStartNanos;
       if (spanDurationNanos <= 0) {
         return;
@@ -306,23 +306,38 @@ private static int addPendingFrameDelay(
   }
 
   /**
-   * Because {@link SentryNanotimeDate#nanoTimestamp()} only gives you millisecond precision, but
-   * diff does ¯\_(ツ)_/¯
+   * Places a span instant on the frame timeline, which {@link android.view.Choreographer} reports
+   * in the {@link System#nanoTime()} timebase.
    *
-   * @param date the input date
-   * @return a non-unix timestamp in nano precision, similar to {@link System#nanoTime()}.
+   * <p>An anchored span's instant inverts to the exact tick it was projected from. That tick is on
+   * {@link io.sentry.time.MonotonicClock} — {@code CLOCK_BOOTTIME} on Android — while frames are on
+   * {@code CLOCK_MONOTONIC}, so crossing between them costs one offset read. The offset changes
+   * whenever the device suspends, so a span that spanned deep sleep lands wrong by the sleep; there
+   * are no frames during sleep, so the honest fix is to skip such a span rather than to guess. That
+   * is the follow-up this method's caller wants, not a reason to keep projecting from the wall
+   * clock.
+   *
+   * @return a non-unix timestamp in nano precision, in the {@link System#nanoTime()} timebase.
    */
-  private static 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);
+  private static long toNanoTime(final @NotNull ISpan span, final @NotNull Timestamp timestamp) {
+    final @Nullable AnchoredClock anchor = span.anchor();
+    if (anchor != null) {
+      // TODO [MAJOR] Cross into the frame timebase before comparing.
+      // The tick is on io.sentry.time.MonotonicClock, which is CLOCK_BOOTTIME on Android, while
+      // Choreographer reports frames on CLOCK_MONOTONIC; the two differ by however long the device
+      // has been suspended. The offset is System.nanoTime() - SystemClock.elapsedRealtimeNanos(),
+      // but reading it from statics here is untestable and it changes on every suspend, so it needs
+      // an injectable seam and a decision about what to do with a span that spanned deep sleep —
+      // there are no frames during sleep, so skipping such a span is more honest than shifting it.
+      // Left unbridged deliberately: this demonstrates the span/anchor integration, not the
+      // timebase fix.
+      return anchor.tickOf(timestamp);
     }
 
-    // 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();
+    // A stated instant — an OTel span, an app-start projection, a SQLite driver span — carries no
+    // tick at all, so there is nothing to invert and the wall clock is all we have.
+    final long nowUnixInNanos = DateUtils.millisToNanos(System.currentTimeMillis());
+    final long shiftInNanos = nowUnixInNanos - timestamp.epochNanos();
     return System.nanoTime() - shiftInNanos;
   }
 

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

@@ -1489,7 +1489,7 @@ class ActivityLifecycleIntegrationTest {
       uiLoadTransaction.children.single { it.operation == ActivityLifecycleIntegration.TTID_OP }
     assertTrue(ttidSpan.isFinished)
     assertTrue(appStartTransaction.isFinished)
-    assertEquals(ttidSpan.finishDate, appStartTransaction.finishDate)
+    assertEquals(ttidSpan.endTimestamp(), appStartTransaction.endTimestamp())
     assertEquals(
       ttidSpan.measurements[MeasurementValue.KEY_TIME_TO_INITIAL_DISPLAY]!!.value,
       AppStartMetrics.getInstance().appStartTimeSpan.durationMs,
@@ -2077,7 +2077,7 @@ class ActivityLifecycleIntegrationTest {
     runFirstDraw(view)
     assertTrue(ttidSpan.isFinished)
     assertTrue(ttfdSpan.isFinished)
-    assertEquals(ttfdSpan.finishDate, ttidSpan.finishDate)
+    assertEquals(ttfdSpan.endTimestamp(), ttidSpan.endTimestamp())
 
     sut.onActivityDestroyed(activity)
 
@@ -2131,8 +2131,8 @@ class ActivityLifecycleIntegrationTest {
     assertNotNull(ttidSpan)
     assertNotNull(ttfdSpan)
 
-    assertEquals(ttidSpan.startDate, fixture.transaction.startDate)
-    assertEquals(ttfdSpan.startDate, fixture.transaction.startDate)
+    assertEquals(ttidSpan.startTimestamp(), fixture.transaction.startTimestamp())
+    assertEquals(ttfdSpan.startTimestamp(), fixture.transaction.startTimestamp())
   }
 
   @Test
@@ -2168,7 +2168,7 @@ class ActivityLifecycleIntegrationTest {
     // 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(ttidSpan.endTimestamp(), ttfdSpan.endTimestamp())
     assertEquals(ttfdSpan.description, "Activity full display - Deadline Exceeded")
   }
 

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

@@ -1,5 +1,6 @@
 package io.sentry.android.core
 
+import io.sentry.DateUtils
 import io.sentry.ISpan
 import io.sentry.ITransaction
 import io.sentry.NoOpSpan
@@ -8,6 +9,10 @@ import io.sentry.SentryNanotimeDate
 import io.sentry.SpanContext
 import io.sentry.android.core.internal.util.SentryFrameMetricsCollector
 import io.sentry.protocol.MeasurementValue
+import io.sentry.time.AnchoredClock
+import io.sentry.time.EpochClock
+import io.sentry.time.MonotonicClock
+import io.sentry.time.Timestamp
 import java.util.UUID
 import java.util.concurrent.TimeUnit
 import kotlin.test.Test
@@ -49,16 +54,7 @@ class SpanFrameMetricsCollectorTest {
     val span = mock<ISpan>()
     val spanContext = SpanContext("op.fake")
     whenever(span.spanContext).thenReturn(spanContext)
-    whenever(span.startDate)
-      .thenReturn(SentryNanotimeDate(System.currentTimeMillis(), startTimeStampNanos))
-    whenever(span.finishDate)
-      .thenReturn(
-        if (endTimeStampNanos != null) {
-          SentryNanotimeDate(System.currentTimeMillis(), endTimeStampNanos)
-        } else {
-          null
-        }
-      )
+    stubAnchoredTimes(span, startTimeStampNanos, endTimeStampNanos)
     return span
   }
 
@@ -69,19 +65,39 @@ class SpanFrameMetricsCollectorTest {
     val span = mock<ITransaction>()
     val spanContext = SpanContext("op.fake")
     whenever(span.spanContext).thenReturn(spanContext)
-    whenever(span.startDate)
-      .thenReturn(SentryNanotimeDate(System.currentTimeMillis(), startTimeStampNanos))
-    whenever(span.finishDate)
-      .thenReturn(
-        if (endTimeStampNanos != null) {
-          SentryNanotimeDate(System.currentTimeMillis(), endTimeStampNanos)
-        } else {
-          null
-        }
-      )
+    stubAnchoredTimes(span, startTimeStampNanos, endTimeStampNanos)
     return span
   }
 
+  /**
+   * Gives a mocked span the timing shape a real one now has: two instants projected from one
+   * anchor, whose ticks are the values this test feeds the frame collector.
+   */
+  private fun stubAnchoredTimes(span: ISpan, startTick: Long, endTick: Long?) {
+    val clock = FakeClock(startTick)
+    val epoch = EpochClock {
+      Timestamp.ofEpochNanos(DateUtils.millisToNanos(System.currentTimeMillis()))
+    }
+    val anchor = AnchoredClock.create(epoch, clock)
+    val start = anchor.start()
+    val end = endTick?.let {
+      clock.setNanos(it)
+      anchor.now()
+    }
+
+    whenever(span.anchor()).thenReturn(anchor)
+    whenever(span.startTimestamp()).thenReturn(start)
+    whenever(span.endTimestamp()).thenReturn(end)
+  }
+
+  private class FakeClock(private var nanos: Long) : MonotonicClock {
+    override fun tickNanos(): Long = nanos
+
+    fun setNanos(value: Long) {
+      nanos = value
+    }
+  }
+
   private val fixture = Fixture()
 
   @Test

sentry-android-sqlite/src/main/java/io/sentry/sqlite/DriverSpans.kt

@@ -4,29 +4,21 @@ import io.sentry.IScopes
 import io.sentry.ISpan
 import io.sentry.Instrumenter
 import io.sentry.ScopesAdapter
-import io.sentry.SentryDate
 import io.sentry.SentryLongDate
-import io.sentry.SentryNanotimeDate
 import io.sentry.SentryStackTraceFactory
 import io.sentry.SpanDataConvention
 import io.sentry.SpanStatus
 
 private const val SQLITE_TRACE_ORIGIN = "auto.db.sqlite"
 
-/**
- * Sentinel for extracting a [SentryNanotimeDate]'s underlying [System.nanoTime] value via
- * [SentryDate.diff].
- */
-private val EMPTY_NANO_TIME = SentryNanotimeDate(0, 0L)
-
 /** Span instrumentation for [SentrySQLiteDriver]. */
 internal class DriverSpans(private val scopes: IScopes, private val dbMetadata: DbMetadata) {
 
   private val stackTraceFactory = SentryStackTraceFactory(scopes.options)
 
   /**
    * Returns a timestamp in nanoseconds for use with [record]. Timestamp is ns-precise if the active
-   * parent span uses a [SentryNanotimeDate] (the ordinary case); otherwise it's ms-precise.
+   * parent span is anchored (the ordinary case); otherwise it's ms-precise.
    *
    * Note: Internalizing the start time in [record] would shift spans to end-of-work on the trace
    * timeline, which is less desirable; callers capture the start before doing database work and
@@ -104,14 +96,9 @@ internal class DriverSpans(private val scopes: IScopes, private val dbMetadata:
  * END TRANSACTION                     ├███┤   0.33 ms
  * ```
  */
-internal fun ISpan.computeNanoStartTimestampForChild(): Long? {
-  if (startDate !is SentryNanotimeDate) {
-    return null
-  }
-
-  val parentWallClockNanos = startDate.nanoTimestamp()
-  val parentMonotonicNanos = startDate.diff(EMPTY_NANO_TIME)
-  val elapsedSinceParentStart = System.nanoTime() - parentMonotonicNanos
-  // Return the child's absolute start time.
-  return parentWallClockNanos + elapsedSinceParentStart
-}
+internal fun ISpan.computeNanoStartTimestampForChild(): Long? =
+  // An anchored span projects nanosecond instants from the transaction's single wall-clock
+  // reading, so "now" on its own timeline is exactly where a child span should start. No
+  // reconstruction, and no silent drop to millisecond precision when the parent's date happens
+  // not to be anchored.
+  anchor()?.now()?.epochNanos()