From c0718823f0fd5b4b875d1f0798f0346793e59b7b Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Fri, 4 Sep 2026 15:08:08 +0200 Subject: [PATCH] feat(time): Anchor span timestamps on one wall-clock reading (JAVA-572) Demonstrates what AnchoredClock and Timestamp look like once Span and SentryTracer actually use them. Not for merge before the major: it changes a serialized value. SentryTracer takes one epoch reading when it is constructed, pins it to one monotonic tick, and every span below it projects from that anchor rather than reading the wall clock again. Because the projection is affine with slope 1, subtracting any two instants in a transaction is subtracting two ticks, so serialization no longer derives anything: - this.timestamp = DateUtils.nanosToSeconds( - span.getStartDate().laterDateNanosTimestampByDiff(span.getFinishDate())); + this.timestamp = DateUtils.nanosToSeconds(span.endTimestamp().epochNanos()); That is the whole point. laterDateNanosTimestampByDiff exists to rescue a monotonic end out of two dates whose classes happen to cooperate; with one anchor there is nothing to rescue. The two sites that reverse-engineered the hidden System.nanoTime() tick out of SentryNanotimeDate ask the anchor instead, and both sentinels -- SentryNanotimeDate(0, 0) -- are gone. DriverSpans.computeNanoStartTimestampForChild collapses to anchor().now(), and no longer silently drops to millisecond precision when the parent's date is not the class it hoped for. ISpan gains startTimestamp(), endTimestamp() and anchor(). getStartDate() and getFinishDate() stay, as epoch-only views, so the public API still works; at the major they go and the SentryDate overloads of finish() and updateEndDate() go with them. Spans whose instants come from outside the process -- OTel, an app-start projection, a caller-supplied startTimestamp -- report a null anchor and keep wall-clock semantics. That case cannot be improved, because the input carries nothing but an epoch; what changes is that it is now a named branch rather than an instanceof that falls through. Why this waits for the major: a child span's start_timestamp moves by sub-millisecond amounts, because it is projected rather than read. Root spans do not move, the anchor being read at root start. Two things this turned up, both left open on purpose: - The frame timebase. Choreographer reports frames on CLOCK_MONOTONIC while the anchor's tick is CLOCK_BOOTTIME on Android, so SpanFrameMetricsCollector needs an offset it cannot read from statics without becoming untestable, and a decision about spans that spanned deep sleep. Marked TODO [MAJOR] rather than half-solved. - SentryDate has no value equality, so getStartDate() returning a fresh view breaks identity comparisons. The tests here move to Timestamp, which does. Also fixes a test that stubbed dateProvider.now() as a fixed call sequence and so depended on how often unrelated code read the provider. --- .../core/SpanFrameMetricsCollector.java | 59 ++++++---- .../core/ActivityLifecycleIntegrationTest.kt | 10 +- .../core/SpanFrameMetricsCollectorTest.kt | 56 +++++---- .../main/java/io/sentry/sqlite/DriverSpans.kt | 27 ++--- .../ComputeNanoStartTimestampForChildTest.kt | 107 ++++++++--------- .../api/sentry-opentelemetry-bootstrap.api | 6 + .../OtelStrongRefSpanWrapper.java | 17 +++ .../OtelTransactionSpanForwarder.java | 17 +++ .../api/sentry-opentelemetry-core.api | 3 + .../sentry/opentelemetry/OtelSpanWrapper.java | 25 ++++ sentry/api/sentry.api | 16 +++ sentry/src/main/java/io/sentry/ISpan.java | 29 +++++ sentry/src/main/java/io/sentry/NoOpSpan.java | 17 +++ .../main/java/io/sentry/NoOpTransaction.java | 17 +++ .../src/main/java/io/sentry/SentryTracer.java | 60 +++++++++- sentry/src/main/java/io/sentry/Span.java | 109 ++++++++++++------ .../java/io/sentry/protocol/SentrySpan.java | 13 ++- .../io/sentry/protocol/SentryTransaction.java | 11 +- .../main/java/io/sentry/time/Timestamp.java | 3 +- ...efaultCompositePerformanceCollectorTest.kt | 8 +- .../test/java/io/sentry/OutboxSenderTest.kt | 4 + .../test/java/io/sentry/SentryTracerTest.kt | 89 +++++++------- sentry/src/test/java/io/sentry/SpanTest.kt | 62 +++++----- 23 files changed, 508 insertions(+), 257 deletions(-) diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/SpanFrameMetricsCollector.java b/sentry-android-core/src/main/java/io/sentry/android/core/SpanFrameMetricsCollector.java index 074a4a6ea51..4ca850ea5f5 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/SpanFrameMetricsCollector.java +++ b/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()}. + *

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; } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index c79d418efe5..840a97316b9 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/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") } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/SpanFrameMetricsCollectorTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/SpanFrameMetricsCollectorTest.kt index 2b6f19a8d31..14bae4bbe49 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/SpanFrameMetricsCollectorTest.kt +++ b/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() 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() 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 diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DriverSpans.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DriverSpans.kt index b3c0eb7c713..9637d9dc9a5 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DriverSpans.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DriverSpans.kt @@ -4,21 +4,13 @@ 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) { @@ -26,7 +18,7 @@ internal class DriverSpans(private val scopes: IScopes, private val dbMetadata: /** * 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() diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt index 13ae1389b77..5122f4f49fa 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt @@ -2,8 +2,11 @@ package io.sentry.sqlite import io.sentry.DateUtils import io.sentry.ISpan -import io.sentry.SentryLongDate -import io.sentry.SentryNanotimeDate +import io.sentry.time.AnchoredClock +import io.sentry.time.EpochClock +import io.sentry.time.MonotonicClock +import io.sentry.time.Timestamp +import java.util.concurrent.TimeUnit.MILLISECONDS import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertNull @@ -14,86 +17,72 @@ import org.mockito.kotlin.whenever class ComputeNanoStartTimestampForChildTest { @Test - fun `returns parent wall clock plus elapsed monotonic time since parent started`() { - val wallClockMillis = 1_000_000L - val elapsedNanos = 500_000L - val parentMonotonicNanos = System.nanoTime() - elapsedNanos - val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) + fun `returns the parent's own timeline projected to now`() { + val clock = FakeClock() + val span = anchoredSpan(WALL_CLOCK_MILLIS, clock) - val timestamp = span.computeNanoStartTimestampForChild()!! + clock.advanceNanos(500_000L) - val elapsedSinceParentStart = timestamp - DateUtils.millisToNanos(wallClockMillis) - assertTrue(elapsedSinceParentStart >= elapsedNanos) - assertTrue(elapsedSinceParentStart < elapsedNanos + TEST_SLACK_NANOS) + assertEquals( + DateUtils.millisToNanos(WALL_CLOCK_MILLIS) + 500_000L, + span.computeNanoStartTimestampForChild(), + ) } @Test - fun `same millisecond wall clocks with different monotonic offsets produce distinct ordered timestamps`() { - val wallClockMillis = 1_000_000L - val wallClockNanos = DateUtils.millisToNanos(wallClockMillis) - val earlierParentMonotonicNanos = System.nanoTime() - 200_000L - val laterParentMonotonicNanos = System.nanoTime() - 800_000L - val earlierSpan = spanWithNanotimeStart(wallClockMillis, earlierParentMonotonicNanos) - val laterSpan = spanWithNanotimeStart(wallClockMillis, laterParentMonotonicNanos) + fun `returns the parent's start when no time has elapsed since it started`() { + val span = anchoredSpan(WALL_CLOCK_MILLIS, FakeClock()) assertEquals( - earlierSpan.startDate.nanoTimestamp(), - laterSpan.startDate.nanoTimestamp(), - "Raw parent timestamps share the same ms-quantized value", + DateUtils.millisToNanos(WALL_CLOCK_MILLIS), + span.computeNanoStartTimestampForChild(), ) - - val earlier = earlierSpan.computeNanoStartTimestampForChild()!! - val later = laterSpan.computeNanoStartTimestampForChild()!! - - assertTrue(earlier > wallClockNanos) - assertTrue(later > wallClockNanos) - assertTrue(earlier < later) - assertTrue(later - earlier >= 500_000L) - } - - @Test - fun `returns parent wall clock when no monotonic time has elapsed since parent started`() { - val wallClockMillis = 1_000_000L - val parentMonotonicNanos = System.nanoTime() - val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) - - val elapsedSinceParentStart = - span.computeNanoStartTimestampForChild()!! - DateUtils.millisToNanos(wallClockMillis) - assertTrue(elapsedSinceParentStart >= 0L) - assertTrue(elapsedSinceParentStart < TEST_SLACK_NANOS) } @Test - fun `works when parent wall clock differs from millisecond baseline`() { - val wallClockMillis = 1_000_001L - val elapsedNanos = 1_500_000L - val parentMonotonicNanos = System.nanoTime() - elapsedNanos - val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) - - val elapsedSinceParentStart = - span.computeNanoStartTimestampForChild()!! - DateUtils.millisToNanos(wallClockMillis) - assertTrue(elapsedSinceParentStart >= elapsedNanos) - assertTrue(elapsedSinceParentStart < elapsedNanos + TEST_SLACK_NANOS) + fun `keeps nanosecond resolution even though the wall anchor is millisecond-quantized`() { + val clock = FakeClock() + val span = anchoredSpan(WALL_CLOCK_MILLIS, clock) + val wallClockNanos = DateUtils.millisToNanos(WALL_CLOCK_MILLIS) + + clock.advanceNanos(200_000L) + val earlier = span.computeNanoStartTimestampForChild()!! + clock.advanceNanos(600_000L) + val later = span.computeNanoStartTimestampForChild()!! + + // Both fall inside the same wall-clock millisecond, yet stay distinct and ordered — the + // resolution comes off the monotonic clock, not off the anchor. + assertTrue(earlier > wallClockNanos) + assertTrue(later - earlier == 600_000L) + assertTrue(later - wallClockNanos < MILLISECONDS.toNanos(1)) } @Test - fun `returns null when start date is not SentryNanotimeDate`() { + fun `returns null when the parent span is not anchored`() { val span = mock() - whenever(span.startDate).thenReturn(SentryLongDate(DateUtils.millisToNanos(1_000_000L))) + whenever(span.anchor()).thenReturn(null) assertNull(span.computeNanoStartTimestampForChild()) } - private fun spanWithNanotimeStart(wallClockMillis: Long, parentMonotonicNanos: Long): ISpan { - val startDate = SentryNanotimeDate(wallClockMillis, parentMonotonicNanos) + private fun anchoredSpan(wallClockMillis: Long, clock: FakeClock): ISpan { + val epoch = EpochClock { Timestamp.ofEpochNanos(DateUtils.millisToNanos(wallClockMillis)) } val span = mock() - whenever(span.startDate).thenReturn(startDate) + whenever(span.anchor()).thenReturn(AnchoredClock.create(epoch, clock)) return span } - companion object { + private class FakeClock : MonotonicClock { + private var nanos = 0L + + override fun tickNanos(): Long = nanos - // Upper bound for monotonic drift while the test body runs. - private const val TEST_SLACK_NANOS = 50_000_000L + fun advanceNanos(amount: Long) { + nanos += amount + } + } + + companion object { + private const val WALL_CLOCK_MILLIS = 1_000_000L } } diff --git a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/api/sentry-opentelemetry-bootstrap.api b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/api/sentry-opentelemetry-bootstrap.api index 1f81e4324d4..a25855bce7a 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/api/sentry-opentelemetry-bootstrap.api +++ b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/api/sentry-opentelemetry-bootstrap.api @@ -44,6 +44,8 @@ public final class io/sentry/opentelemetry/OtelSpanFactory : io/sentry/ISpanFact public final class io/sentry/opentelemetry/OtelStrongRefSpanWrapper : io/sentry/opentelemetry/IOtelSpanWrapper { public fun (Lio/opentelemetry/api/trace/Span;Lio/sentry/opentelemetry/IOtelSpanWrapper;)V public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -89,6 +91,7 @@ public final class io/sentry/opentelemetry/OtelStrongRefSpanWrapper : io/sentry/ public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun storeInContext (Lio/opentelemetry/context/Context;)Lio/opentelemetry/context/Context; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; @@ -99,6 +102,8 @@ public final class io/sentry/opentelemetry/OtelStrongRefSpanWrapper : io/sentry/ public final class io/sentry/opentelemetry/OtelTransactionSpanForwarder : io/sentry/ITransaction { public fun (Lio/sentry/opentelemetry/IOtelSpanWrapper;)V public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -144,6 +149,7 @@ public final class io/sentry/opentelemetry/OtelTransactionSpanForwarder : io/sen public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public fun traceContext ()Lio/sentry/TraceContext; diff --git a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelStrongRefSpanWrapper.java b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelStrongRefSpanWrapper.java index 907d71a278b..f33378cfb20 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelStrongRefSpanWrapper.java +++ b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelStrongRefSpanWrapper.java @@ -20,6 +20,8 @@ import io.sentry.protocol.MeasurementValue; import io.sentry.protocol.SentryId; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import java.util.List; import java.util.Map; import org.jetbrains.annotations.ApiStatus; @@ -321,4 +323,19 @@ public void setContext(@Nullable String key, @Nullable Object context) { public void addFeatureFlag(final @Nullable String flag, final @Nullable Boolean result) { delegate.addFeatureFlag(flag, result); } + + @Override + public @NotNull Timestamp startTimestamp() { + return delegate.startTimestamp(); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return delegate.endTimestamp(); + } + + @Override + public @Nullable AnchoredClock anchor() { + return delegate.anchor(); + } } diff --git a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelTransactionSpanForwarder.java b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelTransactionSpanForwarder.java index e3cdfc4be3b..7a2657d26af 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelTransactionSpanForwarder.java +++ b/sentry-opentelemetry/sentry-opentelemetry-bootstrap/src/main/java/io/sentry/opentelemetry/OtelTransactionSpanForwarder.java @@ -19,6 +19,8 @@ import io.sentry.protocol.Contexts; import io.sentry.protocol.SentryId; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import io.sentry.util.Objects; import java.util.ArrayList; import java.util.List; @@ -314,4 +316,19 @@ public void setName(@NotNull String name, @NotNull TransactionNameSource nameSou public void addFeatureFlag(final @Nullable String flag, final @Nullable Boolean result) { rootSpan.addFeatureFlag(flag, result); } + + @Override + public @NotNull Timestamp startTimestamp() { + return rootSpan.startTimestamp(); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return rootSpan.endTimestamp(); + } + + @Override + public @Nullable AnchoredClock anchor() { + return rootSpan.anchor(); + } } diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/api/sentry-opentelemetry-core.api b/sentry-opentelemetry/sentry-opentelemetry-core/api/sentry-opentelemetry-core.api index 3ed25d1a9cf..137ffa00dbf 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/api/sentry-opentelemetry-core.api +++ b/sentry-opentelemetry/sentry-opentelemetry-core/api/sentry-opentelemetry-core.api @@ -58,6 +58,8 @@ public final class io/sentry/opentelemetry/OtelSpanUtils { public final class io/sentry/opentelemetry/OtelSpanWrapper : io/sentry/opentelemetry/IOtelSpanWrapper { public fun (Lio/opentelemetry/sdk/trace/ReadWriteSpan;Lio/sentry/IScopes;Lio/sentry/SentryDate;Lio/sentry/TracesSamplingDecision;Lio/sentry/opentelemetry/IOtelSpanWrapper;Lio/sentry/SpanId;Lio/sentry/Baggage;)V public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -103,6 +105,7 @@ public final class io/sentry/opentelemetry/OtelSpanWrapper : io/sentry/opentelem public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun storeInContext (Lio/opentelemetry/context/Context;)Lio/opentelemetry/context/Context; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OtelSpanWrapper.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OtelSpanWrapper.java index 80da51f9db7..f5d28034cee 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OtelSpanWrapper.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OtelSpanWrapper.java @@ -28,6 +28,8 @@ import io.sentry.protocol.MeasurementValue; import io.sentry.protocol.SentryId; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.Objects; import java.lang.ref.WeakReference; @@ -554,4 +556,27 @@ public void close() { otelScope.close(); } } + + /** + * OTel hands us epoch nanos at both ends and no tick, so these instants are stated rather than + * projected and {@link #anchor()} is null. A duration taken across them is a wall-clock + * difference — the one case the anchored design cannot improve, because the input carries nothing + * else. + */ + @Override + public @NotNull Timestamp startTimestamp() { + return Timestamp.ofEpochNanos(startTimestamp.nanoTimestamp()); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return finishedTimestamp == null + ? null + : Timestamp.ofEpochNanos(finishedTimestamp.nanoTimestamp()); + } + + @Override + public @Nullable AnchoredClock anchor() { + return null; + } } diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 8193d61651d..33ffa89e8d8 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -1177,6 +1177,8 @@ public abstract interface class io/sentry/ISocketTagger { public abstract interface class io/sentry/ISpan { public abstract fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public abstract fun anchor ()Lio/sentry/time/AnchoredClock; + public abstract fun endTimestamp ()Lio/sentry/time/Timestamp; public abstract fun finish ()V public abstract fun finish (Lio/sentry/SpanStatus;)V public abstract fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -1211,6 +1213,7 @@ public abstract interface class io/sentry/ISpan { public abstract fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public abstract fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public abstract fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public abstract fun startTimestamp ()Lio/sentry/time/Timestamp; public abstract fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public abstract fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public abstract fun traceContext ()Lio/sentry/TraceContext; @@ -1927,6 +1930,8 @@ public final class io/sentry/NoOpSocketTagger : io/sentry/ISocketTagger { public final class io/sentry/NoOpSpan : io/sentry/ISpan { public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -1962,6 +1967,7 @@ public final class io/sentry/NoOpSpan : io/sentry/ISpan { public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public fun traceContext ()Lio/sentry/TraceContext; @@ -1976,6 +1982,8 @@ public final class io/sentry/NoOpSpanFactory : io/sentry/ISpanFactory { public final class io/sentry/NoOpTransaction : io/sentry/ITransaction { public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -2022,6 +2030,7 @@ public final class io/sentry/NoOpTransaction : io/sentry/ITransaction { public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public fun traceContext ()Lio/sentry/TraceContext; @@ -4243,6 +4252,8 @@ public final class io/sentry/SentryTracer : io/sentry/ITransaction { public fun (Lio/sentry/TransactionContext;Lio/sentry/IScopes;)V public fun (Lio/sentry/TransactionContext;Lio/sentry/IScopes;Lio/sentry/TransactionOptions;)V public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -4292,6 +4303,7 @@ public final class io/sentry/SentryTracer : io/sentry/ITransaction { public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public fun traceContext ()Lio/sentry/TraceContext; @@ -4388,6 +4400,8 @@ public final class io/sentry/ShutdownHookIntegration : io/sentry/Integration, ja public final class io/sentry/Span : io/sentry/ISpan { public fun (Lio/sentry/TransactionContext;Lio/sentry/SentryTracer;Lio/sentry/IScopes;Lio/sentry/SpanOptions;)V public fun addFeatureFlag (Ljava/lang/String;Ljava/lang/Boolean;)V + public fun anchor ()Lio/sentry/time/AnchoredClock; + public fun endTimestamp ()Lio/sentry/time/Timestamp; public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V @@ -4429,6 +4443,7 @@ public final class io/sentry/Span : io/sentry/ISpan { public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SentryDate;Lio/sentry/Instrumenter;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; public fun startChild (Ljava/lang/String;Ljava/lang/String;Lio/sentry/SpanOptions;)Lio/sentry/ISpan; + public fun startTimestamp ()Lio/sentry/time/Timestamp; public fun toBaggageHeader (Ljava/util/List;)Lio/sentry/BaggageHeader; public fun toSentryTrace ()Lio/sentry/SentryTraceHeader; public fun traceContext ()Lio/sentry/TraceContext; @@ -7641,6 +7656,7 @@ public final class io/sentry/time/SystemEpochClock : io/sentry/time/EpochClock { } public final class io/sentry/time/Timestamp { + public fun anchor ()Lio/sentry/time/AnchoredClock; public fun epochNanos ()J public fun equals (Ljava/lang/Object;)Z public fun hashCode ()I diff --git a/sentry/src/main/java/io/sentry/ISpan.java b/sentry/src/main/java/io/sentry/ISpan.java index 9c55cdc3201..ab3910ac2eb 100644 --- a/sentry/src/main/java/io/sentry/ISpan.java +++ b/sentry/src/main/java/io/sentry/ISpan.java @@ -1,6 +1,8 @@ package io.sentry; import io.sentry.protocol.Contexts; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import java.util.List; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; @@ -279,6 +281,33 @@ default ISpan startChild( @Nullable SentryDate getFinishDate(); + /** + * When this span started, as an instant projected from {@link #anchor()}. + * + *

Replaces {@link #getStartDate()}. The difference that matters is not the type: two instants + * from one anchor are images of the same tick origin, so subtracting them reports measured time, + * whereas two {@link SentryDate}s may or may not, depending on the runtime class of each. + */ + @ApiStatus.Internal + @NotNull + Timestamp startTimestamp(); + + /** When this span ended, or null while it is still running. */ + @ApiStatus.Internal + @Nullable + Timestamp endTimestamp(); + + /** + * The clock this span's instants were projected from, or null when they were stated from outside + * the process — an OTel span, or a caller-supplied {@code startTimestamp}. + * + *

Exposed so that in-process consumers can recover the tick a span was measured at, via {@link + * AnchoredClock#tickOf}, instead of reverse-engineering it out of a {@link SentryNanotimeDate}. + */ + @ApiStatus.Internal + @Nullable + AnchoredClock anchor(); + /** * Whether this span instance is a NOOP that doesn't collect information * diff --git a/sentry/src/main/java/io/sentry/NoOpSpan.java b/sentry/src/main/java/io/sentry/NoOpSpan.java index 676c539942d..a72285ce3ae 100644 --- a/sentry/src/main/java/io/sentry/NoOpSpan.java +++ b/sentry/src/main/java/io/sentry/NoOpSpan.java @@ -2,6 +2,8 @@ import io.sentry.protocol.Contexts; import io.sentry.protocol.SentryId; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import java.util.List; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; @@ -200,4 +202,19 @@ public void setContext(@Nullable String key, @Nullable Object context) {} @Override public void addFeatureFlag(final @Nullable String flag, final @Nullable Boolean result) {} + + @Override + public @NotNull Timestamp startTimestamp() { + return Timestamp.ofEpochNanos(0); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return null; + } + + @Override + public @Nullable AnchoredClock anchor() { + return null; + } } diff --git a/sentry/src/main/java/io/sentry/NoOpTransaction.java b/sentry/src/main/java/io/sentry/NoOpTransaction.java index 1f34870c9ad..9526f74cb00 100644 --- a/sentry/src/main/java/io/sentry/NoOpTransaction.java +++ b/sentry/src/main/java/io/sentry/NoOpTransaction.java @@ -3,6 +3,8 @@ import io.sentry.protocol.Contexts; import io.sentry.protocol.SentryId; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import java.util.Collections; import java.util.List; import org.jetbrains.annotations.ApiStatus; @@ -255,4 +257,19 @@ public boolean isNoOp() { @Override public void addFeatureFlag(final @Nullable String flag, final @Nullable Boolean result) {} + + @Override + public @NotNull Timestamp startTimestamp() { + return Timestamp.ofEpochNanos(0); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return null; + } + + @Override + public @Nullable AnchoredClock anchor() { + return null; + } } diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index d60187cb4d5..6ec64b016f9 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -5,6 +5,8 @@ import io.sentry.protocol.SentryId; import io.sentry.protocol.SentryTransaction; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.CollectionUtils; import io.sentry.util.Objects; @@ -25,6 +27,14 @@ @ApiStatus.Internal public final class SentryTracer implements ITransaction { private final @NotNull SentryId eventId = new SentryId(); + + /** + * The one wall-clock reading this transaction makes. Declared before {@link #root} so that the + * root span, constructed inside this class's constructor, already sees a usable anchor — Java + * initialises fields in declaration order. + */ + private final @NotNull AnchoredClock anchor; + private final @NotNull Span root; private final @NotNull List children = new CopyOnWriteArrayList<>(); private final @NotNull IScopes scopes; @@ -74,6 +84,9 @@ public SentryTracer( Objects.requireNonNull(context, "context is required"); Objects.requireNonNull(scopes, "scopes are required"); + this.anchor = + AnchoredClock.create( + scopes.getOptions().getEpochClock(), scopes.getOptions().getMonotonicClock()); this.root = new Span(context, this, scopes, transactionOptions); this.name = context.getName(); @@ -160,7 +173,7 @@ private void onDeadlineTimeoutReached() { return; } - final @NotNull SentryDate finishTimestamp = scopes.getOptions().getDateProvider().now(); + final @NotNull Timestamp finishTimestamp = anchor.now(); // abort all child-spans first, this ensures the transaction can be finished, // even if waitForChildren is true @@ -182,8 +195,20 @@ public void finish( @Nullable SentryDate finishDate, boolean dropIfNoChildren, @Nullable Hint hint) { + finish( + status, + finishDate == null ? null : Timestamp.ofEpochNanos(finishDate.nanoTimestamp()), + dropIfNoChildren, + hint); + } + + void finish( + @Nullable SpanStatus status, + @Nullable Timestamp finishDate, + boolean dropIfNoChildren, + @Nullable Hint hint) { // try to get the high precision timestamp from the root span - SentryDate finishTimestamp = root.getFinishDate(); + @Nullable Timestamp finishTimestamp = root.endTimestamp(); // if a finishDate was passed in, use that instead if (finishDate != null) { @@ -192,7 +217,7 @@ public void finish( // if it's not set -> fallback to the current time if (finishTimestamp == null) { - finishTimestamp = scopes.getOptions().getDateProvider().now(); + finishTimestamp = anchor.now(); } // auto-finish any idle spans first @@ -344,11 +369,31 @@ private void cancelDeadlineTimer() { return children; } + @NotNull + AnchoredClock getAnchor() { + return anchor; + } + @Override public @NotNull SentryDate getStartDate() { return this.root.getStartDate(); } + @Override + public @NotNull Timestamp startTimestamp() { + return this.root.startTimestamp(); + } + + @Override + public @Nullable Timestamp endTimestamp() { + return this.root.endTimestamp(); + } + + @Override + public @Nullable AnchoredClock anchor() { + return this.root.anchor(); + } + @Override public @Nullable SentryDate getFinishDate() { return this.root.getFinishDate(); @@ -557,7 +602,7 @@ private void setDefaultSpanData(final @NotNull ISpan span) { * that no profile was recorded, e.g. when the OS rate limits profiling requests. Spans that no * profile covers drop the reference here, so they don't point to a profile that never arrives. */ - private void dropUnrecordedProfilerIds(final @NotNull SentryDate finishTimestamp) { + private void dropUnrecordedProfilerIds(final @NotNull Timestamp finishTimestamp) { final @NotNull IContinuousProfiler continuousProfiler = scopes.getOptions().getContinuousProfiler(); if (continuousProfiler instanceof NoOpContinuousProfiler) { @@ -591,7 +636,7 @@ private void dropUnrecordedProfilerIds(final @NotNull SentryDate finishTimestamp private boolean isProfileMissing( final @NotNull IContinuousProfiler continuousProfiler, final @NotNull Span span, - final @NotNull SentryDate finishTimestamp) { + final @NotNull Timestamp finishTimestamp) { final @Nullable Object data = span.getData(SpanDataConvention.PROFILER_ID); if (!(data instanceof String)) { return false; @@ -604,10 +649,13 @@ private boolean isProfileMissing( return false; } final @Nullable SentryDate spanFinishDate = span.getFinishDate(); + // IContinuousProfiler is public API and still speaks SentryDate; convert at the boundary return continuousProfiler.getProfileRecordingState( profilerId, span.getStartDate(), - spanFinishDate != null ? spanFinishDate : finishTimestamp) + spanFinishDate != null + ? spanFinishDate + : new SentryLongDate(finishTimestamp.epochNanos())) == ProfileRecordingState.NOT_RECORDED; } diff --git a/sentry/src/main/java/io/sentry/Span.java b/sentry/src/main/java/io/sentry/Span.java index 7ee7eed1900..a62b3950093 100644 --- a/sentry/src/main/java/io/sentry/Span.java +++ b/sentry/src/main/java/io/sentry/Span.java @@ -3,6 +3,8 @@ import io.sentry.protocol.Contexts; import io.sentry.protocol.MeasurementValue; import io.sentry.protocol.SentryId; +import io.sentry.time.AnchoredClock; +import io.sentry.time.Timestamp; import io.sentry.util.Objects; import java.util.ArrayList; import java.util.Iterator; @@ -17,11 +19,16 @@ @ApiStatus.Internal public final class Span implements ISpan { - /** The moment in time when span was started. */ - private @NotNull SentryDate startTimestamp; + /** + * When the span started and ended, projected from the transaction's {@link AnchoredClock} — or + * stated directly, when a caller supplied them. + * + *

One anchor per transaction is what makes {@code end - start} a tick difference rather than + * the difference of two independent wall-clock readings. + */ + private @NotNull Timestamp start; - /** The moment in time when span has ended. */ - private @Nullable SentryDate timestamp; + private @Nullable Timestamp end; private final @NotNull SpanContext context; @@ -61,12 +68,7 @@ public final class Span implements ISpan { this.scopes = Objects.requireNonNull(scopes, "Scopes are required"); this.options = options; this.spanFinishedCallback = spanFinishedCallback; - final @Nullable SentryDate startTimestamp = options.getStartTimestamp(); - if (startTimestamp != null) { - this.startTimestamp = startTimestamp; - } else { - this.startTimestamp = scopes.getOptions().getDateProvider().now(); - } + this.start = resolveStart(options, transaction); } public Span( @@ -79,23 +81,45 @@ public Span( this.transaction = Objects.requireNonNull(sentryTracer, "sentryTracer is required"); this.scopes = Objects.requireNonNull(scopes, "scopes are required"); this.spanFinishedCallback = null; - final @Nullable SentryDate startTimestamp = options.getStartTimestamp(); - if (startTimestamp != null) { - this.startTimestamp = startTimestamp; - } else { - this.startTimestamp = scopes.getOptions().getDateProvider().now(); - } + this.start = resolveStart(options, sentryTracer); this.options = options; } + private static @NotNull Timestamp resolveStart( + final @NotNull SpanOptions options, final @NotNull SentryTracer transaction) { + final @Nullable SentryDate stated = options.getStartTimestamp(); + return stated != null + ? Timestamp.ofEpochNanos(stated.nanoTimestamp()) + : transaction.getAnchor().now(); + } + @Override public @NotNull SentryDate getStartDate() { - return startTimestamp; + return new SentryLongDate(start.epochNanos()); } @Override public @Nullable SentryDate getFinishDate() { - return timestamp; + return end == null ? null : new SentryLongDate(end.epochNanos()); + } + + @Override + public @NotNull Timestamp startTimestamp() { + return start; + } + + @Override + public @Nullable Timestamp endTimestamp() { + return end; + } + + @Override + public @Nullable AnchoredClock anchor() { + // Both endpoints have to come from the anchor for a tick to mean anything; a stated one does + // not, and a projected end paired with a stated start would place the span wrongly. + final boolean anchored = + start.anchor() != null && (end == null || end.anchor() == start.anchor()); + return anchored ? start.anchor() : null; } @Override @@ -180,7 +204,7 @@ public void finish() { @Override public void finish(@Nullable SpanStatus status) { - finish(status, scopes.getOptions().getDateProvider().now()); + finish(status, (Timestamp) null); } /** @@ -191,16 +215,25 @@ public void finish(@Nullable SpanStatus status) { */ @Override public void finish(final @Nullable SpanStatus status, final @Nullable SentryDate timestamp) { + finish(status, timestamp == null ? null : Timestamp.ofEpochNanos(timestamp.nanoTimestamp())); + } + + /** + * The anchored counterpart of {@link #finish(SpanStatus, SentryDate)}, used by {@link + * SentryTracer} so that a span it stamps keeps the transaction's anchor rather than being demoted + * to a stated instant. + */ + void finish(final @Nullable SpanStatus status, final @Nullable Timestamp end) { // the span can be finished only once if (finished || !isFinishing.compareAndSet(false, true)) { return; } this.context.setStatus(status); - this.timestamp = timestamp == null ? scopes.getOptions().getDateProvider().now() : timestamp; + this.end = end == null ? transaction.getAnchor().now() : end; if (options.isTrimStart() || options.isTrimEnd()) { - @Nullable SentryDate minChildStart = null; - @Nullable SentryDate maxChildEnd = null; + @Nullable Timestamp minChildStart = null; + @Nullable Timestamp maxChildEnd = null; // The root span should be trimmed based on all children, but the other spans, like the // jetpack composition should be trimmed based on its direct children only @@ -209,23 +242,25 @@ public void finish(final @Nullable SpanStatus status, final @Nullable SentryDate ? transaction.getChildren() : getDirectChildren(); for (final Span child : children) { - if (minChildStart == null || child.getStartDate().isBefore(minChildStart)) { - minChildStart = child.getStartDate(); + final @NotNull Timestamp childStart = child.startTimestamp(); + if (minChildStart == null || childStart.epochNanos() < minChildStart.epochNanos()) { + minChildStart = childStart; } - if (maxChildEnd == null - || (child.getFinishDate() != null && child.getFinishDate().isAfter(maxChildEnd))) { - maxChildEnd = child.getFinishDate(); + final @Nullable Timestamp childEnd = child.endTimestamp(); + if (childEnd != null + && (maxChildEnd == null || childEnd.epochNanos() > maxChildEnd.epochNanos())) { + maxChildEnd = childEnd; } } if (options.isTrimStart() && minChildStart != null - && startTimestamp.isBefore(minChildStart)) { - updateStartDate(minChildStart); + && start.epochNanos() < minChildStart.epochNanos()) { + this.start = minChildStart; } if (options.isTrimEnd() && maxChildEnd != null - && (this.timestamp == null || this.timestamp.isAfter(maxChildEnd))) { - updateEndDate(maxChildEnd); + && this.end.epochNanos() > maxChildEnd.epochNanos()) { + this.end = maxChildEnd; } } @@ -406,8 +441,12 @@ public Map getMeasurements() { @Override public boolean updateEndDate(final @NotNull SentryDate date) { - if (this.timestamp != null) { - this.timestamp = date; + return updateEndDate(Timestamp.ofEpochNanos(date.nanoTimestamp())); + } + + boolean updateEndDate(final @NotNull Timestamp date) { + if (this.end != null) { + this.end = date; return true; } return false; @@ -437,10 +476,6 @@ SpanFinishedCallback getSpanFinishedCallback() { return spanFinishedCallback; } - private void updateStartDate(@NotNull SentryDate date) { - this.startTimestamp = date; - } - @NotNull SpanOptions getOptions() { return options; diff --git a/sentry/src/main/java/io/sentry/protocol/SentrySpan.java b/sentry/src/main/java/io/sentry/protocol/SentrySpan.java index 58930ec1a87..059a48dad13 100644 --- a/sentry/src/main/java/io/sentry/protocol/SentrySpan.java +++ b/sentry/src/main/java/io/sentry/protocol/SentrySpan.java @@ -65,14 +65,15 @@ public SentrySpan(final @NotNull Span span, final @Nullable Map final Map measurementsCopy = CollectionUtils.newConcurrentHashMap(span.getMeasurements()); this.measurements = measurementsCopy != null ? measurementsCopy : new ConcurrentHashMap<>(); - // we lose precision here, from potential nanosecond precision down to 10 microsecond precision + // Both endpoints are projections of the transaction's one anchor, so the server subtracting + // them yields the time this span measured. No derivation needed: the end is not a second + // wall-clock reading, it is the anchor plus a tick difference. + // We lose precision here, from nanosecond precision down to 10 microsecond precision. this.timestamp = - span.getFinishDate() == null + span.endTimestamp() == null ? null - : DateUtils.nanosToSeconds( - span.getStartDate().laterDateNanosTimestampByDiff(span.getFinishDate())); - // we lose precision here, from potential nanosecond precision down to 10 microsecond precision - this.startTimestamp = DateUtils.nanosToSeconds(span.getStartDate().nanoTimestamp()); + : DateUtils.nanosToSeconds(span.endTimestamp().epochNanos()); + this.startTimestamp = DateUtils.nanosToSeconds(span.startTimestamp().epochNanos()); this.data = data; final @NotNull IFeatureFlagBuffer featureFlagBuffer = span.getSpanContext().getFeatureFlagBuffer(); diff --git a/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java b/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java index ab6ff10a4d8..4d9639d9446 100644 --- a/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java +++ b/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java @@ -58,14 +58,13 @@ public final class SentryTransaction extends SentryBaseEvent public SentryTransaction(final @NotNull SentryTracer sentryTracer) { super(sentryTracer.getEventId()); Objects.requireNonNull(sentryTracer, "sentryTracer is required"); - // we lose precision here, from potential nanosecond precision down to 10 microsecond precision - this.startTimestamp = DateUtils.nanosToSeconds(sentryTracer.getStartDate().nanoTimestamp()); - // we lose precision here, from potential nanosecond precision down to 10 microsecond precision + // Anchored, like the child spans: see SentrySpan's constructor. + // We lose precision here, from nanosecond precision down to 10 microsecond precision. + this.startTimestamp = DateUtils.nanosToSeconds(sentryTracer.startTimestamp().epochNanos()); + final @Nullable io.sentry.time.Timestamp end = sentryTracer.endTimestamp(); this.timestamp = DateUtils.nanosToSeconds( - sentryTracer - .getStartDate() - .laterDateNanosTimestampByDiff(sentryTracer.getFinishDate())); + end != null ? end.epochNanos() : sentryTracer.startTimestamp().epochNanos()); this.transaction = sentryTracer.getName(); for (final Span span : sentryTracer.getChildren()) { if (Boolean.TRUE.equals(span.isSampled())) { diff --git a/sentry/src/main/java/io/sentry/time/Timestamp.java b/sentry/src/main/java/io/sentry/time/Timestamp.java index 0c476db7c8e..7d8c2dfc6e5 100644 --- a/sentry/src/main/java/io/sentry/time/Timestamp.java +++ b/sentry/src/main/java/io/sentry/time/Timestamp.java @@ -47,8 +47,7 @@ public long epochNanos() { } /** The clock that projected this instant, or null if it was read or stated directly. */ - @Nullable - AnchoredClock anchor() { + public @Nullable AnchoredClock anchor() { return anchor; } diff --git a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt index d259100853c..8c9b6da77a7 100644 --- a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt +++ b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt @@ -190,7 +190,9 @@ class DefaultCompositePerformanceCollectorTest { SentryNanotimeDate(TimeUnit.SECONDS.toMillis(100), TimeUnit.SECONDS.toNanos(100)), SentryNanotimeDate(TimeUnit.SECONDS.toMillis(131), TimeUnit.SECONDS.toNanos(131)), ) - whenever(mockDateProvider.now()).thenReturn(dates[0], dates[0], dates[0], dates[1]) + // The first reading anchors the collector, every later one is a sampling tick. Stubbing an + // exact call sequence coupled this test to how often unrelated code read the provider. + whenever(mockDateProvider.now()).thenReturn(dates[0], dates[1]) val collector = fixture.getSut { it.dateProvider = mockDateProvider it.addPerformanceCollector(mockCollector) @@ -221,7 +223,9 @@ class DefaultCompositePerformanceCollectorTest { SentryNanotimeDate(TimeUnit.SECONDS.toMillis(100), TimeUnit.SECONDS.toNanos(100)), SentryNanotimeDate(TimeUnit.SECONDS.toMillis(130), TimeUnit.SECONDS.toNanos(130)), ) - whenever(mockDateProvider.now()).thenReturn(dates[0], dates[0], dates[0], dates[1]) + // The first reading anchors the collector, every later one is a sampling tick. Stubbing an + // exact call sequence coupled this test to how often unrelated code read the provider. + whenever(mockDateProvider.now()).thenReturn(dates[0], dates[1]) val collector = fixture.getSut { it.dateProvider = mockDateProvider } collector.start(fixture.transaction1) verify(fixture.mockTimer, never())!!.cancel() diff --git a/sentry/src/test/java/io/sentry/OutboxSenderTest.kt b/sentry/src/test/java/io/sentry/OutboxSenderTest.kt index eecacc95bd2..5a02767ae41 100644 --- a/sentry/src/test/java/io/sentry/OutboxSenderTest.kt +++ b/sentry/src/test/java/io/sentry/OutboxSenderTest.kt @@ -4,6 +4,8 @@ import io.sentry.cache.EnvelopeCache import io.sentry.hints.Retryable import io.sentry.protocol.SentryId import io.sentry.protocol.SentryTransaction +import io.sentry.time.JavaMonotonicClock +import io.sentry.time.SystemEpochClock import io.sentry.util.HintUtils import io.sentry.util.thread.NoOpThreadChecker import java.io.File @@ -38,6 +40,8 @@ class OutboxSenderTest { init { whenever(options.dsn).thenReturn("https://key@sentry.io/proj") whenever(options.dateProvider).thenReturn(SentryNanotimeDateProvider()) + whenever(options.epochClock).thenReturn(SystemEpochClock.getInstance()) + whenever(options.monotonicClock).thenReturn(JavaMonotonicClock.getInstance()) whenever(options.threadChecker).thenReturn(NoOpThreadChecker.getInstance()) whenever(options.continuousProfiler).thenReturn(NoOpContinuousProfiler.getInstance()) whenever(scopes.options).thenReturn(this.options) diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 7c6324db0a7..32ac3d8443c 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -25,7 +25,6 @@ import org.mockito.kotlin.anyOrNull import org.mockito.kotlin.argumentCaptor import org.mockito.kotlin.atLeastOnce import org.mockito.kotlin.check -import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never import org.mockito.kotlin.spy @@ -142,13 +141,13 @@ class SentryTracerTest { @Test fun `when transaction is created, startTimestamp is set`() { val tracer = fixture.getSut() - assertNotNull(tracer.startDate) + assertNotNull(tracer.startTimestamp()) } @Test fun `when transaction is created, timestamp is not set`() { val tracer = fixture.getSut() - assertNull(tracer.finishDate) + assertNull(tracer.endTimestamp()) } @Test @@ -173,14 +172,14 @@ class SentryTracerTest { fun `when transaction is finished, timestamp is set`() { val tracer = fixture.getSut() tracer.finish() - assertNotNull(tracer.finishDate) + assertNotNull(tracer.endTimestamp()) } @Test fun `when transaction is finished with status, timestamp and status are set`() { val tracer = fixture.getSut() tracer.finish(SpanStatus.ABORTED) - assertNotNull(tracer.finishDate) + assertNotNull(tracer.endTimestamp()) assertEquals(SpanStatus.ABORTED, tracer.status) } @@ -193,7 +192,7 @@ class SentryTracerTest { 0, ) tracer.finish(SpanStatus.ABORTED, date) - assertEquals(tracer.finishDate!!.nanoTimestamp(), date.nanoTimestamp()) + assertEquals(tracer.endTimestamp()!!.epochNanos(), date.nanoTimestamp()) assertEquals(SpanStatus.ABORTED, tracer.status) } @@ -357,7 +356,10 @@ class SentryTracerTest { coveredSpan.finish() whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())).thenAnswer { invocation -> - if (invocation.getArgument(1) === uncoveredSpan.startDate) + if ( + invocation.getArgument(1).nanoTimestamp() == + uncoveredSpan.startTimestamp().epochNanos() + ) ProfileRecordingState.NOT_RECORDED else ProfileRecordingState.RECORDED } @@ -410,10 +412,15 @@ class SentryTracerTest { tracer.finish() + val startTimes = argumentCaptor() val endTimes = argumentCaptor() verify(continuousProfiler, atLeastOnce()) - .getProfileRecordingState(any(), eq(unfinishedSpan.startDate), endTimes.capture()) - assertThat(endTimes.lastValue.isAfter(unfinishedSpan.startDate)).isTrue() + .getProfileRecordingState(any(), startTimes.capture(), endTimes.capture()) + // SentryDate has no value equality, so match on the instant rather than with eq() + assertThat(startTimes.allValues.map { it.nanoTimestamp() }) + .contains(unfinishedSpan.startTimestamp().epochNanos()) + assertThat(endTimes.lastValue.nanoTimestamp()) + .isGreaterThan(unfinishedSpan.startTimestamp().epochNanos()) } @Test @@ -612,7 +619,7 @@ class SentryTracerTest { val span = tracer.startChild("op") as Span assertNotNull(span) assertNotNull(span.spanId) - assertNotNull(span.startDate) + assertNotNull(span.startTimestamp()) } @Test @@ -643,7 +650,7 @@ class SentryTracerTest { val span = tracer.startChild("op", "description") as Span assertNotNull(span) assertNotNull(span.spanId) - assertNotNull(span.startDate) + assertNotNull(span.startTimestamp()) assertEquals("op", span.operation) assertEquals("description", span.description) } @@ -677,10 +684,10 @@ class SentryTracerTest { val span = tracer.startChild("op", "description", sentryDate) as Span assertNotNull(span) assertNotNull(span.spanId) - assertNotNull(span.startDate) + assertNotNull(span.startTimestamp()) assertEquals("op", span.operation) assertEquals("description", span.description) - assertEquals(sentryDate, span.startDate) + assertEquals(sentryDate.nanoTimestamp(), span.startTimestamp().epochNanos()) } @Test @@ -735,7 +742,7 @@ class SentryTracerTest { transaction.throwable = ex transaction.finish(SpanStatus.OK) - val timestamp = transaction.finishDate + val timestamp = transaction.endTimestamp() transaction.finish(SpanStatus.UNKNOWN_ERROR) @@ -750,7 +757,7 @@ class SentryTracerTest { ) assertEquals(SpanStatus.OK, transaction.status) - assertEquals(timestamp, transaction.finishDate) + assertEquals(timestamp, transaction.endTimestamp()) } @Test @@ -808,14 +815,14 @@ class SentryTracerTest { val date = SentryNanotimeDate(0, 0) val transaction = fixture.getSut(startTimestamp = date) - assertSame(date, transaction.startDate) + assertEquals(date.nanoTimestamp(), transaction.startTimestamp().epochNanos()) } @Test fun `when startTimestamp is nullable, set it automatically`() { val transaction = fixture.getSut(startTimestamp = null) - assertNotNull(transaction.startDate) + assertNotNull(transaction.startTimestamp()) } @Test @@ -1227,7 +1234,7 @@ class SentryTracerTest { .captureTransaction( check { assertEquals(2, it.spans.size) - assertEquals(transaction.root.finishDate, span2.finishDate) + assertEquals(transaction.root.endTimestamp(), span2.endTimestamp()) }, anyOrNull(), anyOrNull(), @@ -1426,10 +1433,7 @@ class SentryTracerTest { .captureTransaction( check { assertEquals(1, it.spans.size) - assertEquals( - transaction.root.finishDate!!.nanoTimestamp(), - span.finishDate!!.nanoTimestamp(), - ) + assertEquals(transaction.root.endTimestamp(), span.endTimestamp()) }, anyOrNull(), anyOrNull(), @@ -1464,7 +1468,10 @@ class SentryTracerTest { .captureTransaction( check { assertEquals(1, it.spans.size) - assertEquals(transactionFinishDate, span.finishDate) + assertEquals( + transactionFinishDate.nanoTimestamp(), + span.endTimestamp()!!.epochNanos(), + ) }, anyOrNull(), anyOrNull(), @@ -1497,14 +1504,14 @@ class SentryTracerTest { parentSpan.finish() - val expectedParentStartDate = child1.startDate - val expectedParentEndDate = parentSpan.finishDate + val expectedParentStartDate = child1.startTimestamp() + val expectedParentEndDate = parentSpan.endTimestamp() transaction.finish() assertTrue(parentSpan.isFinished) - assertEquals(expectedParentStartDate, parentSpan.startDate) - assertEquals(expectedParentEndDate, parentSpan.finishDate) + assertEquals(expectedParentStartDate, parentSpan.startTimestamp()) + assertEquals(expectedParentEndDate, parentSpan.endTimestamp()) verify(fixture.scopes) .captureTransaction( @@ -1540,14 +1547,14 @@ class SentryTracerTest { parentSpan.finish() - val expectedParentStartDate = parentSpan.startDate - val expectedParentEndDate = child2.finishDate + val expectedParentStartDate = parentSpan.startTimestamp() + val expectedParentEndDate = child2.endTimestamp() transaction.finish() assertTrue(parentSpan.isFinished) - assertEquals(expectedParentStartDate, parentSpan.startDate) - assertEquals(expectedParentEndDate, parentSpan.finishDate) + assertEquals(expectedParentStartDate, parentSpan.startTimestamp()) + assertEquals(expectedParentEndDate, parentSpan.endTimestamp()) verify(fixture.scopes) .captureTransaction( @@ -1591,20 +1598,20 @@ class SentryTracerTest { fun `updateEndDate is ignored and returns false if span is not finished`() { val transaction = fixture.getSut() assertFalse(transaction.isFinished) - assertNull(transaction.finishDate) + assertNull(transaction.endTimestamp()) assertFalse(transaction.updateEndDate(mock())) - assertNull(transaction.finishDate) + assertNull(transaction.endTimestamp()) } @Test fun `updateEndDate updates finishDate and returns true if span is finished`() { val transaction = fixture.getSut() - val endDate: SentryDate = mock() + val endDate = SentryLongDate(1_700_000_000_000_000_000) transaction.finish() assertTrue(transaction.isFinished) - assertNotNull(transaction.finishDate) + assertNotNull(transaction.endTimestamp()) assertTrue(transaction.updateEndDate(endDate)) - assertEquals(endDate, transaction.finishDate) + assertEquals(endDate.nanoTimestamp(), transaction.endTimestamp()!!.epochNanos()) } @Test @@ -1637,19 +1644,19 @@ class SentryTracerTest { // and one span is finished but not the other, and the transaction is force-finished span0.finish(SpanStatus.OK) - val span0FinishDate = span0.finishDate + val span0FinishDate = span0.endTimestamp() transaction.forceFinish(SpanStatus.ABORTED, false, null) // then the first span should keep it's status assertTrue(span0.isFinished) assertEquals(SpanStatus.OK, span0.status) - assertEquals(span0FinishDate, span0.finishDate) + assertEquals(span0FinishDate, span0.endTimestamp()) // and the second span should have the same status as the transaction assertTrue(span1.isFinished) assertEquals(SpanStatus.ABORTED, span1.status) - assertEquals(transaction.finishDate, span1.finishDate) + assertEquals(transaction.endTimestamp(), span1.endTimestamp()) // and the transaction should be captured with both spans verify(fixture.scopes) @@ -1768,11 +1775,11 @@ class SentryTracerTest { fixture.getSut( transactionFinishedCallback = { assertFalse(it.isFinished) - assertNotNull(it.finishDate) + assertNotNull(it.endTimestamp()) } ) assertFalse(transaction.isFinished) - assertNull(transaction.finishDate) + assertNull(transaction.endTimestamp()) transaction.finish() } diff --git a/sentry/src/test/java/io/sentry/SpanTest.kt b/sentry/src/test/java/io/sentry/SpanTest.kt index b61e12ad87f..0799ff98939 100644 --- a/sentry/src/test/java/io/sentry/SpanTest.kt +++ b/sentry/src/test/java/io/sentry/SpanTest.kt @@ -55,7 +55,7 @@ class SpanTest { val span = fixture.getSut() span.finish() - assertNotNull(span.finishDate) + assertNotNull(span.endTimestamp()) } @Test @@ -63,7 +63,7 @@ class SpanTest { val span = fixture.getSut() span.finish(SpanStatus.CANCELLED) - assertNotNull(span.finishDate) + assertNotNull(span.endTimestamp()) assertEquals(SpanStatus.CANCELLED, span.status) } @@ -105,7 +105,7 @@ class SpanTest { assertThat(child.parentSpanId).isEqualTo(parent.spanContext.spanId) assertThat(child.operation).isEqualTo("child-op") assertThat(child.description).isEqualTo("description") - assertThat(child.startDate).isSameInstanceAs(timestamp) + assertThat(child.startTimestamp().epochNanos()).isEqualTo(timestamp.nanoTimestamp()) } @Test @@ -237,14 +237,14 @@ class SpanTest { span.throwable = ex span.finish(SpanStatus.OK) - val timestamp = span.finishDate + val timestamp = span.endTimestamp() span.finish(SpanStatus.UNKNOWN_ERROR) // call only once verify(fixture.scopes).setSpanContext(any(), any(), any()) assertEquals(SpanStatus.OK, span.status) - assertEquals(timestamp, span.finishDate) + assertEquals(timestamp, span.endTimestamp()) } @Test @@ -298,22 +298,22 @@ class SpanTest { // then the span start should match the child // but the finish date should be kept the same - assertEquals(child1.startDate, span.startDate) - assertEquals(finishDate, span.finishDate) + assertEquals(child1.startTimestamp(), span.startTimestamp()) + assertEquals(finishDate.nanoTimestamp(), span.endTimestamp()!!.epochNanos()) } @Test fun `when span trim-start is enabled, do not trim to start of child span if it started earlier`() { // when trim start is enabled val span = fixture.getSut(SpanOptions().apply { isTrimStart = true }) - val startDate = span.startDate + val startDate = span.startTimestamp() // and a child span is created but has an earlier timestamp val child1 = span.startChild( "op1", "desc", - SentryLongDate(span.startDate.nanoTimestamp() - 1000L), + SentryLongDate(span.startTimestamp().epochNanos() - 1000L), Instrumenter.SENTRY, SpanOptions(), ) as Span @@ -321,7 +321,7 @@ class SpanTest { span.finish(SpanStatus.OK) // then the span start should remain unchanged - assertEquals(startDate, span.startDate) + assertEquals(startDate, span.startTimestamp()) } @Test @@ -329,7 +329,7 @@ class SpanTest { // when trim end is enabled val span = fixture.getSut(SpanOptions().apply { isTrimEnd = true }) - val startDate = span.startDate + val startDate = span.startTimestamp() // and a child span is created Thread.sleep(1) @@ -340,8 +340,8 @@ class SpanTest { // then the start should be left unchanged // but the end should match the child - assertEquals(startDate, span.startDate) - assertEquals(child1.finishDate, span.finishDate) + assertEquals(startDate, span.startTimestamp()) + assertEquals(child1.endTimestamp(), span.endTimestamp()) } @Test @@ -349,20 +349,20 @@ class SpanTest { // when trim end is enabled val span = fixture.getSut(SpanOptions().apply { isTrimEnd = true }) - val startDate = span.startDate + val startDate = span.startTimestamp() // and a child span is created, but finished later than the parent val child1 = span.startChild("op1") as Span span.finish(SpanStatus.OK) - val finishDate = span.finishDate!! + val finishDate = span.endTimestamp()!! Thread.sleep(1) child1.finish() // then both start and finish date should be left unchanged - assertEquals(startDate, span.startDate) - assertEquals(finishDate, span.finishDate) + assertEquals(startDate, span.startTimestamp()) + assertEquals(finishDate, span.endTimestamp()) } @Test @@ -395,9 +395,9 @@ class SpanTest { assertTrue(span.isFinished) // then the span start/finish should match its direct children only - assertEquals(child1.startDate, span.startDate) - assertEquals(child2.finishDate, span.finishDate) - assertNotEquals(subChild.finishDate, span.finishDate) + assertEquals(child1.startTimestamp(), span.startTimestamp()) + assertEquals(child2.endTimestamp(), span.endTimestamp()) + assertNotEquals(subChild.endTimestamp(), span.endTimestamp()) } @Test @@ -430,9 +430,9 @@ class SpanTest { assertTrue(span.isFinished) // then the root span start/finish should match first/last of its direct and indirect children - assertEquals(child1.startDate, span.startDate) - assertNotEquals(child2.finishDate, span.finishDate) - assertEquals(subChild.finishDate, span.finishDate) + assertEquals(child1.startTimestamp(), span.startTimestamp()) + assertNotEquals(child2.endTimestamp(), span.endTimestamp()) + assertEquals(subChild.endTimestamp(), span.endTimestamp()) } @Test @@ -467,20 +467,20 @@ class SpanTest { fun `updateEndDate is ignored and returns false if span is not finished`() { val span = fixture.getSut() assertFalse(span.isFinished) - assertNull(span.finishDate) - assertFalse(span.updateEndDate(mock())) - assertNull(span.finishDate) + assertNull(span.endTimestamp()) + assertFalse(span.updateEndDate(mock())) + assertNull(span.endTimestamp()) } @Test fun `updateEndDate updates finishDate and returns true if span is finished`() { val span = fixture.getSut() - val endDate: SentryDate = mock() + val endDate = SentryLongDate(1_700_000_000_000_000_000) span.finish() assertTrue(span.isFinished) - assertNotNull(span.finishDate) + assertNotNull(span.endTimestamp()) assertTrue(span.updateEndDate(endDate)) - assertEquals(endDate, span.finishDate) + assertEquals(endDate.nanoTimestamp(), span.endTimestamp()!!.epochNanos()) } @Test @@ -532,10 +532,10 @@ class SpanTest { val span = fixture.getSut() span.setSpanFinishedCallback { assertFalse(span.isFinished) - assertNotNull(span.finishDate) + assertNotNull(span.endTimestamp()) } assertFalse(span.isFinished) - assertNull(span.finishDate) + assertNull(span.endTimestamp()) span.finish() }