From b9fe70968672211394fbb2297164109c042424de Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 15:56:12 +0200 Subject: [PATCH 1/8] fix(tracing): End timed-out transactions when the timeout fell due (JAVA-642) The idle and deadline timers run on a thread that is frozen while the device is in deep sleep or the process is cached, so a timeout scheduled for 30s can fire hours later. Both callbacks stamped the spans with the wake-up time, turning an app start the user walked away from into a multi-hour transaction. Record when each timeout falls due at scheduling time and stamp with that instead, whenever the timer runs late. The deadline path passes the clamped timestamp down to forceFinish, which stamps every child before the root finishes and so otherwise defeats trimEnd. Fixes #5752 Co-Authored-By: Claude Opus 5 (1M context) --- .../src/main/java/io/sentry/SentryTracer.java | 39 +++++++++++- .../test/java/io/sentry/SentryTracerTest.kt | 60 +++++++++++++++++++ 2 files changed, 96 insertions(+), 3 deletions(-) diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index d60187cb4d..822861bfb2 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -40,6 +40,10 @@ public final class SentryTracer implements ITransaction { private volatile @Nullable Future idleTimeoutFuture; private volatile @Nullable Future deadlineTimeoutFuture; + // The instant each timeout is due, projected when its timer is scheduled. See dueDate. + private volatile @Nullable SentryDate idleTimeoutDueDate; + private volatile @Nullable SentryDate deadlineTimeoutDueDate; + // Whether timeout tasks may still be scheduled. Set to false once the tracer is finished. The // executor itself is owned by the options (shared SDK-wide) and obtained from there when needed. private volatile boolean timersEnabled = false; @@ -117,6 +121,7 @@ public void scheduleFinish() { if (idleTimeout != null) { cancelIdleTimer(); isIdleFinishTimerRunning.set(true); + idleTimeoutDueDate = dueDate(idleTimeout); try { idleTimeoutFuture = @@ -140,7 +145,7 @@ public void scheduleFinish() { private void onIdleTimeoutReached() { final @Nullable SpanStatus status = getStatus(); - finish((status != null) ? status : SpanStatus.OK); + finish((status != null) ? status : SpanStatus.OK, notLaterThan(idleTimeoutDueDate)); isIdleFinishTimerRunning.set(false); } @@ -149,18 +154,45 @@ private void onDeadlineTimeoutReached() { forceFinish( (status != null) ? status : SpanStatus.DEADLINE_EXCEEDED, transactionOptions.getIdleTimeout() != null, - null); + null, + notLaterThan(deadlineTimeoutDueDate)); isDeadlineTimerRunning.set(false); } + /** The instant at which a timeout of {@code timeoutMillis}, scheduled now, falls due. */ + private @NotNull SentryDate dueDate(final long timeoutMillis) { + final @NotNull SentryDate now = scopes.getOptions().getDateProvider().now(); + return new SentryLongDate(now.nanoTimestamp() + DateUtils.millisToNanos(timeoutMillis)); + } + + /** + * The timeout timers run on a thread that is frozen while the device sleeps or the process is + * cached, so a timeout scheduled for 30s can fire hours later. Stamping the spans with the + * wake-up time turns an app start the user walked away from into a multi-hour transaction, so we + * report the instant the timeout fell due instead. + */ + private @NotNull SentryDate notLaterThan(final @Nullable SentryDate dueDate) { + final @NotNull SentryDate now = scopes.getOptions().getDateProvider().now(); + return dueDate != null && now.isAfter(dueDate) ? dueDate : now; + } + @Override public @NotNull void forceFinish( final @NotNull SpanStatus status, final boolean dropIfNoChildren, final @Nullable Hint hint) { + forceFinish(status, dropIfNoChildren, hint, null); + } + + private void forceFinish( + final @NotNull SpanStatus status, + final boolean dropIfNoChildren, + final @Nullable Hint hint, + final @Nullable SentryDate finishDate) { if (isFinished()) { return; } - final @NotNull SentryDate finishTimestamp = scopes.getOptions().getDateProvider().now(); + final @NotNull SentryDate finishTimestamp = + finishDate != null ? finishDate : scopes.getOptions().getDateProvider().now(); // abort all child-spans first, this ensures the transaction can be finished, // even if waitForChildren is true @@ -310,6 +342,7 @@ private void scheduleDeadlineTimeout() { if (timersEnabled) { cancelDeadlineTimer(); isDeadlineTimerRunning.set(true); + deadlineTimeoutDueDate = dueDate(deadlineTimeOut); try { deadlineTimeoutFuture = scopes diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 7c6324db0a..33718bc6b7 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -10,6 +10,7 @@ import io.sentry.test.getProperty import io.sentry.util.thread.IThreadChecker import java.time.LocalDateTime import java.time.ZoneOffset +import java.util.concurrent.TimeUnit import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertFalse @@ -79,6 +80,14 @@ class SentryTracerTest { private val fixture = Fixture() + /** Lets a test place "now" wherever it likes, to stand in for a timer that fired late. */ + private class ControllableDateProvider(var date: SentryDate) : SentryDateProvider { + override fun now(): SentryDate = date + } + + private fun SentryDate.plus(amount: Long, unit: TimeUnit): SentryDate = + SentryLongDate(nanoTimestamp() + unit.toNanos(amount)) + @Test fun `transfer origin from transaction options to transaction context`() { fixture.getSut() @@ -1103,6 +1112,57 @@ class SentryTracerTest { assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status) } + @Test + fun `when the deadline timer fires late, tx and children end when the deadline fell due`() { + val start = SentryLongDate(1_000_000_000L) + val dateProvider = ControllableDateProvider(start) + val transaction = + fixture.getSut( + optionsConfiguration = { it.dateProvider = dateProvider }, + deadlineTimeout = 20, + ) + val span = transaction.startChild("op") + + // the device slept through the deadline, so the timer thread only runs again hours later + dateProvider.date = start.plus(3, TimeUnit.HOURS) + await.untilFalse(transaction.isDeadlineTimerRunning) + + val due = start.plus(20, TimeUnit.MILLISECONDS) + assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(due.nanoTimestamp()) + assertThat(span.finishDate!!.nanoTimestamp()).isEqualTo(due.nanoTimestamp()) + } + + @Test + fun `when the deadline timer fires on time, the transaction ends now`() { + val start = SentryLongDate(1_000_000_000L) + val dateProvider = ControllableDateProvider(start) + val transaction = + fixture.getSut( + optionsConfiguration = { it.dateProvider = dateProvider }, + deadlineTimeout = 20, + ) + transaction.startChild("op") + + await.untilFalse(transaction.isDeadlineTimerRunning) + + // the due date is in the future here, so it must not be used to stamp the end + assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(start.nanoTimestamp()) + } + + @Test + fun `when the idle timer fires late, the transaction ends when the idle timeout fell due`() { + val start = SentryLongDate(1_000_000_000L) + val dateProvider = ControllableDateProvider(start) + val transaction = + fixture.getSut(optionsConfiguration = { it.dateProvider = dateProvider }, idleTimeout = 20) + + dateProvider.date = start.plus(3, TimeUnit.HOURS) + await.untilFalse(transaction.isFinishTimerRunning) + + assertThat(transaction.finishDate!!.nanoTimestamp()) + .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + } + @Test fun `when transaction is finished before deadline is reached, deadline should not be running anymore`() { val transaction = fixture.getSut(deadlineTimeout = 1000) From be1bb70ca0a89e7a57fcce151250cada72d31a0a Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 15:57:08 +0200 Subject: [PATCH 2/8] changelog --- CHANGELOG.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 09622493a2..d385b83b1c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Fixes + +- End a timed-out transaction at the moment its timeout fell due, rather than whenever the timer thread next gets to run. A device that slept, or froze the process, through an idle or deadline timeout used to turn an abandoned app start into a multi-hour transaction ([#6091](https://github.com/getsentry/sentry-java/pull/6091)) + ## 8.56.0 ### Behavioral Changes From a33769c47a50c70ce92d20197daddce7bfbf87bd Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 16:03:51 +0200 Subject: [PATCH 3/8] ref(tracing): Decide timeout expiry on a monotonic Deadline Whether a timeout expired was decided by comparing a fresh wall-clock reading against the projected due date. That is a duration measured from two independent wall-clock readings, which the clock can lengthen, shorten or make negative. A backward step while the timer waits made an expired timeout look pending, so the transaction was stamped with the wake-up time again; a forward step truncated a transaction whose timeout had not expired. Measure expiry on io.sentry.time.Deadline, which runs on the monotonic ticker and, on Android, on CLOCK_BOOTTIME so the interval includes deep sleep. The instant to end at stays a wall-clock timestamp, projected once from the same reading that sets the deadline. An expired timeout now always ends the transaction at the instant it fell due, including an on-time fire, which drops the scheduler jitter from the reported duration. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/main/java/io/sentry/SentryTracer.java | 65 ++++++++++++++----- .../test/java/io/sentry/SentryTracerTest.kt | 44 ++++++++++++- 2 files changed, 89 insertions(+), 20 deletions(-) diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 822861bfb2..f5b57cd58e 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -5,6 +5,7 @@ import io.sentry.protocol.SentryId; import io.sentry.protocol.SentryTransaction; import io.sentry.protocol.TransactionNameSource; +import io.sentry.time.Deadline; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.CollectionUtils; import io.sentry.util.Objects; @@ -15,6 +16,7 @@ import java.util.Map; import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicReference; import org.jetbrains.annotations.ApiStatus; @@ -40,9 +42,9 @@ public final class SentryTracer implements ITransaction { private volatile @Nullable Future idleTimeoutFuture; private volatile @Nullable Future deadlineTimeoutFuture; - // The instant each timeout is due, projected when its timer is scheduled. See dueDate. - private volatile @Nullable SentryDate idleTimeoutDueDate; - private volatile @Nullable SentryDate deadlineTimeoutDueDate; + // When each timeout falls due, captured when its timer is scheduled. See Expiry. + private volatile @Nullable Expiry idleExpiry; + private volatile @Nullable Expiry deadlineExpiry; // Whether timeout tasks may still be scheduled. Set to false once the tracer is finished. The // executor itself is owned by the options (shared SDK-wide) and obtained from there when needed. @@ -121,7 +123,7 @@ public void scheduleFinish() { if (idleTimeout != null) { cancelIdleTimer(); isIdleFinishTimerRunning.set(true); - idleTimeoutDueDate = dueDate(idleTimeout); + idleExpiry = expiryIn(idleTimeout); try { idleTimeoutFuture = @@ -145,7 +147,7 @@ public void scheduleFinish() { private void onIdleTimeoutReached() { final @Nullable SpanStatus status = getStatus(); - finish((status != null) ? status : SpanStatus.OK, notLaterThan(idleTimeoutDueDate)); + finish((status != null) ? status : SpanStatus.OK, finishDateOf(idleExpiry)); isIdleFinishTimerRunning.set(false); } @@ -155,25 +157,52 @@ private void onDeadlineTimeoutReached() { (status != null) ? status : SpanStatus.DEADLINE_EXCEEDED, transactionOptions.getIdleTimeout() != null, null, - notLaterThan(deadlineTimeoutDueDate)); + finishDateOf(deadlineExpiry)); isDeadlineTimerRunning.set(false); } - /** The instant at which a timeout of {@code timeoutMillis}, scheduled now, falls due. */ - private @NotNull SentryDate dueDate(final long timeoutMillis) { - final @NotNull SentryDate now = scopes.getOptions().getDateProvider().now(); - return new SentryLongDate(now.nanoTimestamp() + DateUtils.millisToNanos(timeoutMillis)); + /** When a timeout of {@code timeoutMillis}, scheduled now, falls due. */ + private @NotNull Expiry expiryIn(final long timeoutMillis) { + final @NotNull SentryOptions options = scopes.getOptions(); + return new Expiry( + Deadline.after(options.getMonotonicTicker(), timeoutMillis, TimeUnit.MILLISECONDS), + new SentryLongDate( + options.getDateProvider().now().nanoTimestamp() + + DateUtils.millisToNanos(timeoutMillis))); + } + + private static @Nullable SentryDate finishDateOf(final @Nullable Expiry expiry) { + return expiry == null ? null : expiry.finishDate(); } /** - * The timeout timers run on a thread that is frozen while the device sleeps or the process is - * cached, so a timeout scheduled for 30s can fire hours later. Stamping the spans with the - * wake-up time turns an app start the user walked away from into a multi-hour transaction, so we - * report the instant the timeout fell due instead. + * When a timeout falls due, in the two forms the tracer needs. + * + *

The timers run on a thread that is frozen while the device sleeps or the process is cached, + * so a timeout scheduled for 30s can fire hours later. Ending the transaction at the wake-up time + * turns an app start the user walked away from into a multi-hour transaction, so an expired + * timeout ends it at the instant it fell due instead. + * + *

Whether the timeout expired is a duration, so it is measured on a {@link Deadline}: the + * executor's own delay runs on a clock that stops during deep sleep, and the wall clock can step + * either way while the timer waits. The instant to end at is a wall-clock timestamp, so it is + * projected once, here, from the same reading that sets the deadline. */ - private @NotNull SentryDate notLaterThan(final @Nullable SentryDate dueDate) { - final @NotNull SentryDate now = scopes.getOptions().getDateProvider().now(); - return dueDate != null && now.isAfter(dueDate) ? dueDate : now; + private static final class Expiry { + + private final @NotNull Deadline deadline; + private final @NotNull SentryDate instant; + + Expiry(final @NotNull Deadline deadline, final @NotNull SentryDate instant) { + this.deadline = deadline; + this.instant = instant; + } + + /** The instant to end at, or null to end now because the timeout has not actually expired. */ + @Nullable + SentryDate finishDate() { + return deadline.hasPassed() ? instant : null; + } } @Override @@ -342,7 +371,7 @@ private void scheduleDeadlineTimeout() { if (timersEnabled) { cancelDeadlineTimer(); isDeadlineTimerRunning.set(true); - deadlineTimeoutDueDate = dueDate(deadlineTimeOut); + deadlineExpiry = expiryIn(deadlineTimeOut); try { deadlineTimeoutFuture = scopes diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 33718bc6b7..b9d8f6eecb 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -1133,7 +1133,26 @@ class SentryTracerTest { } @Test - fun `when the deadline timer fires on time, the transaction ends now`() { + fun `when the wall clock steps back past the deadline, the transaction still ends when it fell due`() { + val start = SentryLongDate(1_000_000_000_000L) + val dateProvider = ControllableDateProvider(start) + val transaction = + fixture.getSut( + optionsConfiguration = { it.dateProvider = dateProvider }, + deadlineTimeout = 20, + ) + + // an NTP correction moves the wall clock backwards while the timer waits, so the due date now + // looks like it is in the future. Whether the deadline expired is not the wall clock's to say. + dateProvider.date = start.plus(-1, TimeUnit.HOURS) + await.untilFalse(transaction.isDeadlineTimerRunning) + + assertThat(transaction.finishDate!!.nanoTimestamp()) + .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + } + + @Test + fun `when the deadline timer fires on time, the transaction ends when it fell due`() { val start = SentryLongDate(1_000_000_000L) val dateProvider = ControllableDateProvider(start) val transaction = @@ -1145,7 +1164,28 @@ class SentryTracerTest { await.untilFalse(transaction.isDeadlineTimerRunning) - // the due date is in the future here, so it must not be used to stamp the end + // an expired deadline ends the transaction at the deadline, not at whenever the timer ran + assertThat(transaction.finishDate!!.nanoTimestamp()) + .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + } + + @Test + fun `when the deadline has not expired, the transaction ends now`() { + val start = SentryLongDate(1_000_000_000L) + val dateProvider = ControllableDateProvider(start) + // scheduling fails, so the tracer finishes inline while the deadline is still in the future + val executor = mock() + whenever(executor.schedule(any(), any())).thenThrow(RuntimeException("rejected")) + + val transaction = + fixture.getSut( + optionsConfiguration = { + it.dateProvider = dateProvider + it.timerExecutorService = executor + }, + deadlineTimeout = 20, + ) + assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(start.nanoTimestamp()) } From 154e04fa629397dd00ddb7e9336f67a7af4d5dd8 Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 16:10:31 +0200 Subject: [PATCH 4/8] ref(tracing): Say why a timeout's end instant stays a SentryDate Co-Authored-By: Claude Opus 5 (1M context) --- .../src/main/java/io/sentry/SentryTracer.java | 22 +++++++++++-------- 1 file changed, 13 insertions(+), 9 deletions(-) diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index f5b57cd58e..41e67c59f2 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -168,11 +168,11 @@ private void onDeadlineTimeoutReached() { Deadline.after(options.getMonotonicTicker(), timeoutMillis, TimeUnit.MILLISECONDS), new SentryLongDate( options.getDateProvider().now().nanoTimestamp() - + DateUtils.millisToNanos(timeoutMillis))); + + TimeUnit.MILLISECONDS.toNanos(timeoutMillis))); } private static @Nullable SentryDate finishDateOf(final @Nullable Expiry expiry) { - return expiry == null ? null : expiry.finishDate(); + return expiry == null ? null : expiry.expiredAt(); } /** @@ -185,23 +185,27 @@ private void onDeadlineTimeoutReached() { * *

Whether the timeout expired is a duration, so it is measured on a {@link Deadline}: the * executor's own delay runs on a clock that stops during deep sleep, and the wall clock can step - * either way while the timer waits. The instant to end at is a wall-clock timestamp, so it is - * projected once, here, from the same reading that sets the deadline. + * either way while the timer waits. + * + *

The instant to end at stays a {@link SentryDate} rather than an {@link + * io.sentry.time.Timestamp}. It will be subtracted from the span timestamps around it, so it has + * to be read from the same clock they are, and those come from {@link + * SentryOptions#getDateProvider()}. It is projected once, here, from a single reading. */ private static final class Expiry { private final @NotNull Deadline deadline; - private final @NotNull SentryDate instant; + private final @NotNull SentryDate expiredAt; - Expiry(final @NotNull Deadline deadline, final @NotNull SentryDate instant) { + Expiry(final @NotNull Deadline deadline, final @NotNull SentryDate expiredAt) { this.deadline = deadline; - this.instant = instant; + this.expiredAt = expiredAt; } /** The instant to end at, or null to end now because the timeout has not actually expired. */ @Nullable - SentryDate finishDate() { - return deadline.hasPassed() ? instant : null; + SentryDate expiredAt() { + return deadline.hasPassed() ? expiredAt : null; } } From f84e7ab16696336cde1ad3f2ef33961cd8ddd56b Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 16:28:04 +0200 Subject: [PATCH 5/8] ref(tracing): Hold a timeout's end instant as a Timestamp The tracer's timeout logic now works in io.sentry.time terms throughout: the duration on a Deadline, the instant as a Timestamp read from the options' EpochClock. Timestamp.toSentryDate bridges to the type the span API still takes, at the single point of use. Co-Authored-By: Claude Opus 5 (1M context) --- sentry/api/sentry.api | 1 + .../src/main/java/io/sentry/SentryTracer.java | 21 ++-- .../main/java/io/sentry/time/Timestamp.java | 13 ++- .../test/java/io/sentry/SentryTracerTest.kt | 102 +++++++++--------- 4 files changed, 77 insertions(+), 60 deletions(-) diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 24635fc5dd..4220a85bdf 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -7642,6 +7642,7 @@ public final class io/sentry/time/Timestamp { public fun equals (Ljava/lang/Object;)Z public fun hashCode ()I public static fun ofEpochNanos (J)Lio/sentry/time/Timestamp; + public fun toSentryDate ()Lio/sentry/SentryDate; public fun toString ()Ljava/lang/String; } diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 41e67c59f2..70a11ce544 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -6,6 +6,7 @@ import io.sentry.protocol.SentryTransaction; import io.sentry.protocol.TransactionNameSource; import io.sentry.time.Deadline; +import io.sentry.time.Timestamp; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.CollectionUtils; import io.sentry.util.Objects; @@ -166,13 +167,14 @@ private void onDeadlineTimeoutReached() { final @NotNull SentryOptions options = scopes.getOptions(); return new Expiry( Deadline.after(options.getMonotonicTicker(), timeoutMillis, TimeUnit.MILLISECONDS), - new SentryLongDate( - options.getDateProvider().now().nanoTimestamp() + Timestamp.ofEpochNanos( + options.getEpochClock().now().epochNanos() + TimeUnit.MILLISECONDS.toNanos(timeoutMillis))); } private static @Nullable SentryDate finishDateOf(final @Nullable Expiry expiry) { - return expiry == null ? null : expiry.expiredAt(); + final @Nullable Timestamp expiredAt = expiry == null ? null : expiry.expiredAt(); + return expiredAt == null ? null : expiredAt.toSentryDate(); } /** @@ -187,24 +189,23 @@ private void onDeadlineTimeoutReached() { * executor's own delay runs on a clock that stops during deep sleep, and the wall clock can step * either way while the timer waits. * - *

The instant to end at stays a {@link SentryDate} rather than an {@link - * io.sentry.time.Timestamp}. It will be subtracted from the span timestamps around it, so it has - * to be read from the same clock they are, and those come from {@link - * SentryOptions#getDateProvider()}. It is projected once, here, from a single reading. + *

The instant to end at is a {@link Timestamp} from {@link SentryOptions#getEpochClock()}, + * projected once from a single reading, and bridged to the {@link SentryDate} the span API takes + * only at the point of use. */ private static final class Expiry { private final @NotNull Deadline deadline; - private final @NotNull SentryDate expiredAt; + private final @NotNull Timestamp expiredAt; - Expiry(final @NotNull Deadline deadline, final @NotNull SentryDate expiredAt) { + Expiry(final @NotNull Deadline deadline, final @NotNull Timestamp expiredAt) { this.deadline = deadline; this.expiredAt = expiredAt; } /** The instant to end at, or null to end now because the timeout has not actually expired. */ @Nullable - SentryDate expiredAt() { + Timestamp expiredAt() { return deadline.hasPassed() ? expiredAt : null; } } diff --git a/sentry/src/main/java/io/sentry/time/Timestamp.java b/sentry/src/main/java/io/sentry/time/Timestamp.java index d703cfb9c9..04e3616e48 100644 --- a/sentry/src/main/java/io/sentry/time/Timestamp.java +++ b/sentry/src/main/java/io/sentry/time/Timestamp.java @@ -1,5 +1,7 @@ package io.sentry.time; +import io.sentry.SentryDate; +import io.sentry.SentryLongDate; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; @@ -47,11 +49,20 @@ public boolean equals(final @Nullable Object other) { @Override public int hashCode() { - return (int) (epochNanos ^ (epochNanos >>> 32)); + return Long.hashCode(epochNanos); } @Override public @NotNull String toString() { return "Timestamp{epochNanos=" + epochNanos + '}'; } + + /** + * This forms an easy bridge between our old API and the new API. + * + * @return a SentryDate implemented by a SentryLongDate + */ + public SentryDate toSentryDate() { + return new SentryLongDate(epochNanos); + } } diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index b9d8f6eecb..65b6ed7de7 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -7,6 +7,8 @@ import io.sentry.protocol.TransactionNameSource import io.sentry.protocol.User import io.sentry.test.createTestScopes import io.sentry.test.getProperty +import io.sentry.time.EpochClock +import io.sentry.time.Timestamp import io.sentry.util.thread.IThreadChecker import java.time.LocalDateTime import java.time.ZoneOffset @@ -35,8 +37,15 @@ import org.mockito.kotlin.verify import org.mockito.kotlin.whenever class SentryTracerTest { + /** {@link SentryOptions#getEpochClock()} has no setter, so a test fakes it by overriding. */ + private class TestOptions : SentryOptions() { + var testEpochClock: EpochClock? = null + + override fun getEpochClock(): EpochClock = testEpochClock ?: super.getEpochClock() + } + private class Fixture { - val options = SentryOptions() + val options = TestOptions() val scopes: Scopes val compositePerformanceCollector: CompositePerformanceCollector @@ -80,13 +89,19 @@ class SentryTracerTest { private val fixture = Fixture() - /** Lets a test place "now" wherever it likes, to stand in for a timer that fired late. */ - private class ControllableDateProvider(var date: SentryDate) : SentryDateProvider { - override fun now(): SentryDate = date + /** + * One movable "now", behind both clocks the tracer reads: the date provider that stamps spans and + * the epoch clock that projects when a timeout falls due. + */ + private class ControllableClock(var epochNanos: Long) { + val dateProvider = SentryDateProvider { SentryLongDate(epochNanos) } + val epochClock = EpochClock { Timestamp.ofEpochNanos(epochNanos) } } - private fun SentryDate.plus(amount: Long, unit: TimeUnit): SentryDate = - SentryLongDate(nanoTimestamp() + unit.toNanos(amount)) + private fun useClock(clock: ControllableClock) { + fixture.options.dateProvider = clock.dateProvider + fixture.options.testEpochClock = clock.epochClock + } @Test fun `transfer origin from transaction options to transaction context`() { @@ -1114,93 +1129,82 @@ class SentryTracerTest { @Test fun `when the deadline timer fires late, tx and children end when the deadline fell due`() { - val start = SentryLongDate(1_000_000_000L) - val dateProvider = ControllableDateProvider(start) - val transaction = - fixture.getSut( - optionsConfiguration = { it.dateProvider = dateProvider }, - deadlineTimeout = 20, - ) + val start = 1_000_000_000_000L + val clock = ControllableClock(start) + useClock(clock) + val transaction = fixture.getSut(deadlineTimeout = 20) val span = transaction.startChild("op") // the device slept through the deadline, so the timer thread only runs again hours later - dateProvider.date = start.plus(3, TimeUnit.HOURS) + clock.epochNanos = start + TimeUnit.HOURS.toNanos(3) await.untilFalse(transaction.isDeadlineTimerRunning) - val due = start.plus(20, TimeUnit.MILLISECONDS) - assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(due.nanoTimestamp()) - assertThat(span.finishDate!!.nanoTimestamp()).isEqualTo(due.nanoTimestamp()) + val due = start + TimeUnit.MILLISECONDS.toNanos(20) + assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(due) + assertThat(span.finishDate!!.nanoTimestamp()).isEqualTo(due) } @Test fun `when the wall clock steps back past the deadline, the transaction still ends when it fell due`() { - val start = SentryLongDate(1_000_000_000_000L) - val dateProvider = ControllableDateProvider(start) - val transaction = - fixture.getSut( - optionsConfiguration = { it.dateProvider = dateProvider }, - deadlineTimeout = 20, - ) + val start = 1_000_000_000_000L + val clock = ControllableClock(start) + useClock(clock) + val transaction = fixture.getSut(deadlineTimeout = 20) - // an NTP correction moves the wall clock backwards while the timer waits, so the due date now - // looks like it is in the future. Whether the deadline expired is not the wall clock's to say. - dateProvider.date = start.plus(-1, TimeUnit.HOURS) + // an NTP correction moves the wall clock backwards while the timer waits, so the due instant + // now looks like it is ahead of us. Whether the deadline expired is not the wall clock's to say + clock.epochNanos = start - TimeUnit.HOURS.toNanos(1) await.untilFalse(transaction.isDeadlineTimerRunning) assertThat(transaction.finishDate!!.nanoTimestamp()) - .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + .isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20)) } @Test fun `when the deadline timer fires on time, the transaction ends when it fell due`() { - val start = SentryLongDate(1_000_000_000L) - val dateProvider = ControllableDateProvider(start) - val transaction = - fixture.getSut( - optionsConfiguration = { it.dateProvider = dateProvider }, - deadlineTimeout = 20, - ) + val start = 1_000_000_000_000L + val clock = ControllableClock(start) + useClock(clock) + val transaction = fixture.getSut(deadlineTimeout = 20) transaction.startChild("op") await.untilFalse(transaction.isDeadlineTimerRunning) // an expired deadline ends the transaction at the deadline, not at whenever the timer ran assertThat(transaction.finishDate!!.nanoTimestamp()) - .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + .isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20)) } @Test fun `when the deadline has not expired, the transaction ends now`() { - val start = SentryLongDate(1_000_000_000L) - val dateProvider = ControllableDateProvider(start) + val start = 1_000_000_000_000L + val clock = ControllableClock(start) + useClock(clock) // scheduling fails, so the tracer finishes inline while the deadline is still in the future val executor = mock() whenever(executor.schedule(any(), any())).thenThrow(RuntimeException("rejected")) val transaction = fixture.getSut( - optionsConfiguration = { - it.dateProvider = dateProvider - it.timerExecutorService = executor - }, + optionsConfiguration = { it.timerExecutorService = executor }, deadlineTimeout = 20, ) - assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(start.nanoTimestamp()) + assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(start) } @Test fun `when the idle timer fires late, the transaction ends when the idle timeout fell due`() { - val start = SentryLongDate(1_000_000_000L) - val dateProvider = ControllableDateProvider(start) - val transaction = - fixture.getSut(optionsConfiguration = { it.dateProvider = dateProvider }, idleTimeout = 20) + val start = 1_000_000_000_000L + val clock = ControllableClock(start) + useClock(clock) + val transaction = fixture.getSut(idleTimeout = 20) - dateProvider.date = start.plus(3, TimeUnit.HOURS) + clock.epochNanos = start + TimeUnit.HOURS.toNanos(3) await.untilFalse(transaction.isFinishTimerRunning) assertThat(transaction.finishDate!!.nanoTimestamp()) - .isEqualTo(start.plus(20, TimeUnit.MILLISECONDS).nanoTimestamp()) + .isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20)) } @Test From 14631c55e38e2ef063125dc5468c5c924e13ce74 Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 16:53:10 +0200 Subject: [PATCH 6/8] test(tracing): Drive the timeout tests off the shared clock fakes FixedEpochClock, TestMonotonicTicker and DeferredExecutorService already existed; the tests were hand-rolling a date-provider fake and waiting on the real timer. Driving the ticker and the timer directly also removes the race between the test advancing its clock and the 20ms timer actually firing. Co-Authored-By: Claude Opus 5 (1M context) --- .../test/java/io/sentry/SentryTracerTest.kt | 87 +++++++++++-------- 1 file changed, 51 insertions(+), 36 deletions(-) diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 65b6ed7de7..950a9c8d06 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -5,10 +5,13 @@ import io.sentry.profiling.ProfileRecordingState import io.sentry.protocol.SentryId import io.sentry.protocol.TransactionNameSource import io.sentry.protocol.User +import io.sentry.test.DeferredExecutorService import io.sentry.test.createTestScopes import io.sentry.test.getProperty import io.sentry.time.EpochClock -import io.sentry.time.Timestamp +import io.sentry.time.FixedEpochClock +import io.sentry.time.MonotonicTicker +import io.sentry.time.TestMonotonicTicker import io.sentry.util.thread.IThreadChecker import java.time.LocalDateTime import java.time.ZoneOffset @@ -37,11 +40,14 @@ import org.mockito.kotlin.verify import org.mockito.kotlin.whenever class SentryTracerTest { - /** {@link SentryOptions#getEpochClock()} has no setter, so a test fakes it by overriding. */ + /** The clocks have getters but no setters on options, so a test fakes them by overriding. */ private class TestOptions : SentryOptions() { var testEpochClock: EpochClock? = null + var testTicker: MonotonicTicker? = null override fun getEpochClock(): EpochClock = testEpochClock ?: super.getEpochClock() + + override fun getMonotonicTicker(): MonotonicTicker = testTicker ?: super.getMonotonicTicker() } private class Fixture { @@ -89,18 +95,30 @@ class SentryTracerTest { private val fixture = Fixture() + /** An arbitrary but fixed instant the clock tests measure from. */ + private val start = 1_000_000_000_000L + /** - * One movable "now", behind both clocks the tracer reads: the date provider that stamps spans and - * the epoch clock that projects when a timeout falls due. + * Everything the timeout logic reads, under the test's control: what time it is, how much time + * has passed, and when the timer gets to run. */ - private class ControllableClock(var epochNanos: Long) { - val dateProvider = SentryDateProvider { SentryLongDate(epochNanos) } - val epochClock = EpochClock { Timestamp.ofEpochNanos(epochNanos) } - } + private class Clocks(startEpochNanos: Long) { + val epoch = FixedEpochClock(startEpochNanos) + val ticker = TestMonotonicTicker() + val timer = DeferredExecutorService() + + /** Time passing for real: every clock moves together, as they do on a device. */ + fun advance(amount: Long, unit: TimeUnit) { + epoch.epochNanos += unit.toNanos(amount) + ticker.advance(amount, unit) + } - private fun useClock(clock: ControllableClock) { - fixture.options.dateProvider = clock.dateProvider - fixture.options.testEpochClock = clock.epochClock + fun installOn(options: TestOptions) { + options.testEpochClock = epoch + options.testTicker = ticker + options.timerExecutorService = timer + options.dateProvider = SentryDateProvider { SentryLongDate(epoch.epochNanos) } + } } @Test @@ -1129,15 +1147,14 @@ class SentryTracerTest { @Test fun `when the deadline timer fires late, tx and children end when the deadline fell due`() { - val start = 1_000_000_000_000L - val clock = ControllableClock(start) - useClock(clock) + val clocks = Clocks(start) + clocks.installOn(fixture.options) val transaction = fixture.getSut(deadlineTimeout = 20) val span = transaction.startChild("op") - // the device slept through the deadline, so the timer thread only runs again hours later - clock.epochNanos = start + TimeUnit.HOURS.toNanos(3) - await.untilFalse(transaction.isDeadlineTimerRunning) + // the device sleeps through the deadline; the timer thread only runs again three hours on + clocks.advance(3, TimeUnit.HOURS) + clocks.timer.runAll() val due = start + TimeUnit.MILLISECONDS.toNanos(20) assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(due) @@ -1146,15 +1163,15 @@ class SentryTracerTest { @Test fun `when the wall clock steps back past the deadline, the transaction still ends when it fell due`() { - val start = 1_000_000_000_000L - val clock = ControllableClock(start) - useClock(clock) + val clocks = Clocks(start) + clocks.installOn(fixture.options) val transaction = fixture.getSut(deadlineTimeout = 20) - // an NTP correction moves the wall clock backwards while the timer waits, so the due instant - // now looks like it is ahead of us. Whether the deadline expired is not the wall clock's to say - clock.epochNanos = start - TimeUnit.HOURS.toNanos(1) - await.untilFalse(transaction.isDeadlineTimerRunning) + // an NTP correction drags the wall clock back while the timer waits, so the due instant now + // looks like it is ahead of us. Whether the deadline expired is not the wall clock's to say + clocks.epoch.epochNanos = start - TimeUnit.HOURS.toNanos(1) + clocks.ticker.advance(20, TimeUnit.MILLISECONDS) + clocks.timer.runAll() assertThat(transaction.finishDate!!.nanoTimestamp()) .isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20)) @@ -1162,13 +1179,13 @@ class SentryTracerTest { @Test fun `when the deadline timer fires on time, the transaction ends when it fell due`() { - val start = 1_000_000_000_000L - val clock = ControllableClock(start) - useClock(clock) + val clocks = Clocks(start) + clocks.installOn(fixture.options) val transaction = fixture.getSut(deadlineTimeout = 20) transaction.startChild("op") - await.untilFalse(transaction.isDeadlineTimerRunning) + clocks.advance(20, TimeUnit.MILLISECONDS) + clocks.timer.runAll() // an expired deadline ends the transaction at the deadline, not at whenever the timer ran assertThat(transaction.finishDate!!.nanoTimestamp()) @@ -1177,9 +1194,8 @@ class SentryTracerTest { @Test fun `when the deadline has not expired, the transaction ends now`() { - val start = 1_000_000_000_000L - val clock = ControllableClock(start) - useClock(clock) + val clocks = Clocks(start) + clocks.installOn(fixture.options) // scheduling fails, so the tracer finishes inline while the deadline is still in the future val executor = mock() whenever(executor.schedule(any(), any())).thenThrow(RuntimeException("rejected")) @@ -1195,13 +1211,12 @@ class SentryTracerTest { @Test fun `when the idle timer fires late, the transaction ends when the idle timeout fell due`() { - val start = 1_000_000_000_000L - val clock = ControllableClock(start) - useClock(clock) + val clocks = Clocks(start) + clocks.installOn(fixture.options) val transaction = fixture.getSut(idleTimeout = 20) - clock.epochNanos = start + TimeUnit.HOURS.toNanos(3) - await.untilFalse(transaction.isFinishTimerRunning) + clocks.advance(3, TimeUnit.HOURS) + clocks.timer.runAll() assertThat(transaction.finishDate!!.nanoTimestamp()) .isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20)) From 8ee49a63823c31543f39014eb446a181fe78720a Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 16:59:32 +0200 Subject: [PATCH 7/8] ref(tracing): Read the timeout bridge as a property from Kotlin Rename Timestamp.toSentryDate to getSentryDate so Kotlin callers reach it as expiry?.expiredAt()?.sentryDate, and note at the call sites what the bridge is for and where the tracer reaches into options for its clocks. Also drops a meaningless @NotNull on forceFinish's void return. Co-Authored-By: Claude Opus 5 (1M context) --- sentry/api/sentry.api | 2 +- sentry/src/main/java/io/sentry/SentryTracer.java | 10 ++++++++-- sentry/src/main/java/io/sentry/time/Timestamp.java | 2 +- 3 files changed, 10 insertions(+), 4 deletions(-) diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 4220a85bdf..6a66560e1d 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -7640,9 +7640,9 @@ public final class io/sentry/time/SystemEpochClock : io/sentry/time/EpochClock { public final class io/sentry/time/Timestamp { public fun epochNanos ()J public fun equals (Ljava/lang/Object;)Z + public fun getSentryDate ()Lio/sentry/SentryDate; public fun hashCode ()I public static fun ofEpochNanos (J)Lio/sentry/time/Timestamp; - public fun toSentryDate ()Lio/sentry/SentryDate; public fun toString ()Ljava/lang/String; } diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 70a11ce544..d7b25c08b5 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -164,17 +164,22 @@ private void onDeadlineTimeoutReached() { /** When a timeout of {@code timeoutMillis}, scheduled now, falls due. */ private @NotNull Expiry expiryIn(final long timeoutMillis) { + // Yeah, we can just reach in to that scopes.options and grab whatever we want. Can't even hide + // this one behind an interface. final @NotNull SentryOptions options = scopes.getOptions(); return new Expiry( Deadline.after(options.getMonotonicTicker(), timeoutMillis, TimeUnit.MILLISECONDS), + // This is just the current Timestamp + deadline as a wall clock time. Timestamp.ofEpochNanos( options.getEpochClock().now().epochNanos() + TimeUnit.MILLISECONDS.toNanos(timeoutMillis))); } + // A little bridge between the new Timestamp API and the old SentryDate. private static @Nullable SentryDate finishDateOf(final @Nullable Expiry expiry) { + // In Kotlin it would be expiry?.expiredAt()?.sentryDate if that makes it easier to read. final @Nullable Timestamp expiredAt = expiry == null ? null : expiry.expiredAt(); - return expiredAt == null ? null : expiredAt.toSentryDate(); + return expiredAt == null ? null : expiredAt.getSentryDate(); } /** @@ -211,11 +216,12 @@ Timestamp expiredAt() { } @Override - public @NotNull void forceFinish( + public void forceFinish( final @NotNull SpanStatus status, final boolean dropIfNoChildren, final @Nullable Hint hint) { forceFinish(status, dropIfNoChildren, hint, null); } + // Use the finishDate provided to finish the transaction in case the timeout/deadline has passed. private void forceFinish( final @NotNull SpanStatus status, final boolean dropIfNoChildren, diff --git a/sentry/src/main/java/io/sentry/time/Timestamp.java b/sentry/src/main/java/io/sentry/time/Timestamp.java index 04e3616e48..87395ab8d5 100644 --- a/sentry/src/main/java/io/sentry/time/Timestamp.java +++ b/sentry/src/main/java/io/sentry/time/Timestamp.java @@ -62,7 +62,7 @@ public int hashCode() { * * @return a SentryDate implemented by a SentryLongDate */ - public SentryDate toSentryDate() { + public SentryDate getSentryDate() { return new SentryLongDate(epochNanos); } } From edd56b075ea2e914216c18d8dd85097ab18f61db Mon Sep 17 00:00:00 2001 From: Nelson Osacky Date: Thu, 10 Sep 2026 17:15:56 +0200 Subject: [PATCH 8/8] docs(tracing): Trim the Expiry javadoc The paragraph on which class holds the instant restated the field types. What is left is the part the code cannot say: why a late timer is possible at all, and why only a monotonic deadline can tell. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/main/java/io/sentry/SentryTracer.java | 19 +++++++------------ 1 file changed, 7 insertions(+), 12 deletions(-) diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index d7b25c08b5..caa6fafd3d 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -183,20 +183,15 @@ private void onDeadlineTimeoutReached() { } /** - * When a timeout falls due, in the two forms the tracer needs. + * When a timeout falls due: the instant to end at, and whether it has arrived. * - *

The timers run on a thread that is frozen while the device sleeps or the process is cached, - * so a timeout scheduled for 30s can fire hours later. Ending the transaction at the wake-up time - * turns an app start the user walked away from into a multi-hour transaction, so an expired - * timeout ends it at the instant it fell due instead. + *

The timers run on a thread frozen while the device sleeps or the process is cached, so one + * scheduled for 30s can fire hours later. Ending at the wake-up time turns an app start the user + * walked away from into a multi-hour transaction, so an expired timeout ends at the instant it + * fell due instead. * - *

Whether the timeout expired is a duration, so it is measured on a {@link Deadline}: the - * executor's own delay runs on a clock that stops during deep sleep, and the wall clock can step - * either way while the timer waits. - * - *

The instant to end at is a {@link Timestamp} from {@link SentryOptions#getEpochClock()}, - * projected once from a single reading, and bridged to the {@link SentryDate} the span API takes - * only at the point of use. + *

Only a {@link Deadline} can say whether it expired: the executor's own delay stops during + * deep sleep, and the wall clock can step either way while the timer waits. */ private static final class Expiry {