From 97c001f192b58e08e1d48a9318e313208449b49d Mon Sep 17 00:00:00 2001 From: Matt Van Horn <455140+mvanhorn@users.noreply.github.com> Date: Sat, 11 Jul 2026 00:40:42 -0700 Subject: [PATCH 1/3] fix: guard app-start transaction against doze-skewed start timestamps --- CHANGELOG.md | 1 + .../src/main/java/io/sentry/SentryTracer.java | 50 ++++++- .../test/java/io/sentry/SentryTracerTest.kt | 122 ++++++++++++++++-- 3 files changed, 161 insertions(+), 12 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a3baff8d6b2..41eef7b39fe 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -30,6 +30,7 @@ ### Fixes +- Drop transactions whose deadline timer is delayed by device sleep ([#5752](https://github.com/getsentry/sentry-java/issues/5752)) - Fix main thread identification for tombstone (native crash) events ([#5742](https://github.com/getsentry/sentry-java/pull/5742)) ### Dependencies diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 9729ac406b1..e66d5223812 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -39,6 +39,7 @@ public final class SentryTracer implements ITransaction { private volatile @Nullable TimerTask idleTimeoutTask; private volatile @Nullable TimerTask deadlineTimeoutTask; + private volatile long deadlineTimeoutScheduledAtNanos; private volatile @Nullable Timer timer = null; private final @NotNull AutoClosableReentrantLock timerLock = new AutoClosableReentrantLock(); @@ -146,6 +147,47 @@ private void onIdleTimeoutReached() { } private void onDeadlineTimeoutReached() { + if (isFinished()) { + isDeadlineTimerRunning.set(false); + return; + } + + final @Nullable Long deadlineTimeout = transactionOptions.getDeadlineTimeout(); + if (deadlineTimeout != null) { + final long elapsedNanos = + scopes.getOptions().getDateProvider().now().nanoTimestamp() + - deadlineTimeoutScheduledAtNanos; + if (deadlineTimeout > 0 && DateUtils.nanosToMillis(elapsedNanos) > deadlineTimeout * 2.0) { + scopes + .getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Dropping transaction %s because the deadline timer fired too late", + name); + scopes.configureScope( + scope -> { + scope.withTransaction( + transaction -> { + if (transaction == this) { + scope.clearTransaction(); + } + }); + }); + if (timer != null) { + try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) { + if (timer != null) { + cancelIdleTimer(); + cancelDeadlineTimer(); + timer.cancel(); + timer = null; + } + } + } + return; + } + } + final @Nullable SpanStatus status = getStatus(); forceFinish( (status != null) ? status : SpanStatus.DEADLINE_EXCEEDED, @@ -310,6 +352,8 @@ private void scheduleDeadlineTimeout() { if (timer != null) { cancelDeadlineTimer(); isDeadlineTimerRunning.set(true); + deadlineTimeoutScheduledAtNanos = + scopes.getOptions().getDateProvider().now().nanoTimestamp(); deadlineTimeoutTask = new TimerTask() { @Override @@ -536,7 +580,8 @@ private ISpan createChild( .getLogger() .log( SentryLevel.WARNING, - "Span operation: %s, description: %s dropped due to limit reached. Returning NoOpSpan.", + "Span operation: %s, description: %s dropped due to limit reached. Returning" + + " NoOpSpan.", operation, description); return NoOpSpan.getInstance(); @@ -633,7 +678,8 @@ private void setDefaultSpanData(final @NotNull ISpan span) { .getLogger() .log( SentryLevel.WARNING, - "Span operation: %s, description: %s dropped due to limit reached. Returning NoOpSpan.", + "Span operation: %s, description: %s dropped due to limit reached. Returning" + + " NoOpSpan.", operation, description); return NoOpSpan.getInstance(); diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 3b808dd2220..18cf218eb98 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -1,5 +1,6 @@ package io.sentry +import com.google.common.truth.Truth.assertThat import io.sentry.protocol.SentryId import io.sentry.protocol.TransactionNameSource import io.sentry.protocol.User @@ -28,6 +29,11 @@ import org.mockito.kotlin.verify import org.mockito.kotlin.whenever class SentryTracerTest { + private class MutableDateProvider(var currentTimeMillis: Long = 0) : SentryDateProvider { + override fun now(): SentryDate = + SentryNanotimeDate(currentTimeMillis, DateUtils.millisToNanos(currentTimeMillis)) + } + private class Fixture { val options = SentryOptions() val scopes: Scopes @@ -925,19 +931,83 @@ class SentryTracerTest { } @Test - fun `when deadline is reached transaction is finished`() { - // when a transaction with a deadline timeout is created - // and the tx and child keep on running - val transaction = fixture.getSut(deadlineTimeout = 20) + fun `when deadline is reached on time transaction and children are captured as deadline exceeded`() { + val dateProvider = MutableDateProvider() + val transaction = + fixture.getSut( + optionsConfiguration = { it.setDateProvider(dateProvider) }, + deadlineTimeout = 10_000, + ) val span = transaction.startChild("op") - // and the deadline is exceed - await.untilFalse(transaction.isDeadlineTimerRunning) + dateProvider.currentTimeMillis = 10_000 + transaction.deadlineTimeoutTask!!.run() - // then both tx + span should be force finished - assertEquals(transaction.isFinished, true) - assertEquals(SpanStatus.DEADLINE_EXCEEDED, transaction.status) - assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status) + assertThat(transaction.isFinished).isTrue() + assertThat(transaction.status).isEqualTo(SpanStatus.DEADLINE_EXCEEDED) + assertThat(span.isFinished).isTrue() + assertThat(span.status).isEqualTo(SpanStatus.DEADLINE_EXCEEDED) + verify(fixture.scopes) + .captureTransaction( + check { assertThat(it.status).isEqualTo(SpanStatus.DEADLINE_EXCEEDED) }, + anyOrNull(), + anyOrNull(), + anyOrNull(), + ) + } + + @Test + fun `when deadline timer fires after device sleep transaction is dropped and timers are cancelled`() { + val dateProvider = MutableDateProvider() + val logger = mock() + val transaction = + fixture.getSut( + optionsConfiguration = { + it.setDateProvider(dateProvider) + it.setLogger(logger) + }, + idleTimeout = 60_000, + deadlineTimeout = 10_000, + ) + transaction.startChild("op") + transaction.scheduleFinish() + fixture.scopes.configureScope { it.transaction = transaction } + + dateProvider.currentTimeMillis = 30_000 + transaction.deadlineTimeoutTask!!.run() + + verify(fixture.scopes, never()) + .captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + verify(logger) + .log( + SentryLevel.DEBUG, + "Dropping transaction %s because the deadline timer fired too late", + "name", + ) + assertThat(fixture.scopes.span).isNull() + assertThat(transaction.idleTimeoutTask).isNull() + assertThat(transaction.deadlineTimeoutTask).isNull() + assertThat(transaction.isFinishTimerRunning.get()).isFalse() + assertThat(transaction.isDeadlineTimerRunning.get()).isFalse() + assertThat(transaction.timer).isNull() + } + + @Test + fun `when deadline timer fires at twice the deadline transaction is still captured`() { + val dateProvider = MutableDateProvider() + val transaction = + fixture.getSut( + optionsConfiguration = { it.setDateProvider(dateProvider) }, + deadlineTimeout = 10_000, + ) + + dateProvider.currentTimeMillis = 20_000 + transaction.deadlineTimeoutTask!!.run() + + assertThat(transaction.isFinished).isTrue() + assertThat(transaction.status).isEqualTo(SpanStatus.DEADLINE_EXCEEDED) + verify(fixture.scopes) + .captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) } @Test @@ -953,6 +1023,38 @@ class SentryTracerTest { assertEquals(transaction.isFinished, true) assertEquals(SpanStatus.OK, transaction.status) assertEquals(SpanStatus.OK, span.status) + verify(fixture.scopes) + .captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) + } + + @Test + fun `when idle transaction without children reaches late deadline it is dropped once`() { + val dateProvider = MutableDateProvider() + val logger = mock() + val transaction = + fixture.getSut( + optionsConfiguration = { + it.setDateProvider(dateProvider) + it.setLogger(logger) + }, + idleTimeout = 60_000, + deadlineTimeout = 10_000, + ) + + dateProvider.currentTimeMillis = 30_000 + transaction.deadlineTimeoutTask!!.run() + + verify(fixture.scopes, never()) + .captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + verify(logger, times(1)) + .log( + SentryLevel.DEBUG, + "Dropping transaction %s because the deadline timer fired too late", + "name", + ) + assertThat(transaction.idleTimeoutTask).isNull() + assertThat(transaction.deadlineTimeoutTask).isNull() + assertThat(transaction.timer).isNull() } @Test From 3bc479494db78ed2d2f6827b593e361da16db6ca Mon Sep 17 00:00:00 2001 From: Matt Van Horn <455140+mvanhorn@users.noreply.github.com> Date: Sat, 11 Jul 2026 11:22:18 -0700 Subject: [PATCH 2/3] fix: finish root span on late deadline drop and unblock logger assertions in tests Finish the root span when the deadline timer fires too late so the transaction reads as finished (fixes the device-sleep drop test), enable options.isDebug in the two logger-mock tests so DiagnosticLogger forwards to the mock, and apply spotless formatting. Verified locally: spotlessCheck and the full SentryTracerTest suite pass on JDK 17. --- sentry/src/main/java/io/sentry/SentryTracer.java | 1 + sentry/src/test/java/io/sentry/SentryTracerTest.kt | 10 ++++++---- 2 files changed, 7 insertions(+), 4 deletions(-) diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index e66d5223812..5814a22217c 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -165,6 +165,7 @@ private void onDeadlineTimeoutReached() { SentryLevel.DEBUG, "Dropping transaction %s because the deadline timer fired too late", name); + root.finish(); scopes.configureScope( scope -> { scope.withTransaction( diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 18cf218eb98..29a33860bdd 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -965,6 +965,7 @@ class SentryTracerTest { optionsConfiguration = { it.setDateProvider(dateProvider) it.setLogger(logger) + it.isDebug = true }, idleTimeout = 60_000, deadlineTimeout = 10_000, @@ -975,6 +976,8 @@ class SentryTracerTest { dateProvider.currentTimeMillis = 30_000 transaction.deadlineTimeoutTask!!.run() + assertThat(transaction.isFinished).isTrue() + transaction.finish() verify(fixture.scopes, never()) .captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) @@ -1006,8 +1009,7 @@ class SentryTracerTest { assertThat(transaction.isFinished).isTrue() assertThat(transaction.status).isEqualTo(SpanStatus.DEADLINE_EXCEEDED) - verify(fixture.scopes) - .captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) + verify(fixture.scopes).captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) } @Test @@ -1023,8 +1025,7 @@ class SentryTracerTest { assertEquals(transaction.isFinished, true) assertEquals(SpanStatus.OK, transaction.status) assertEquals(SpanStatus.OK, span.status) - verify(fixture.scopes) - .captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) + verify(fixture.scopes).captureTransaction(any(), anyOrNull(), anyOrNull(), anyOrNull()) } @Test @@ -1036,6 +1037,7 @@ class SentryTracerTest { optionsConfiguration = { it.setDateProvider(dateProvider) it.setLogger(logger) + it.isDebug = true }, idleTimeout = 60_000, deadlineTimeout = 10_000, From 3548a72997cec0c7efdb37a8e4a8c186d6e32329 Mon Sep 17 00:00:00 2001 From: Matt Van Horn <455140+mvanhorn@users.noreply.github.com> Date: Sun, 12 Jul 2026 06:03:06 -0700 Subject: [PATCH 3/3] chore: reference PR number in changelog entry for danger check --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 41eef7b39fe..1032285e315 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -30,7 +30,7 @@ ### Fixes -- Drop transactions whose deadline timer is delayed by device sleep ([#5752](https://github.com/getsentry/sentry-java/issues/5752)) +- Drop transactions whose deadline timer is delayed by device sleep ([#5755](https://github.com/getsentry/sentry-java/pull/5755)) - Fix main thread identification for tombstone (native crash) events ([#5742](https://github.com/getsentry/sentry-java/pull/5742)) ### Dependencies