From b1bdbbb61d35e433ae2b2d7fe44dfd5e06247140 Mon Sep 17 00:00:00 2001 From: Adam Brown Date: Tue, 27 Oct 2026 16:08:09 +0100 Subject: [PATCH] fix(tracing): Stop idle spans from keeping idle transactions alive until their deadline (JAVA-795) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit An idle span (SpanOptions.isIdle) is meant to be finished by its parent transaction when the transaction finishes. Before this commit, SentryTracer treated an unfinished idle span as blocking. Creating one canceled the idle timer; SentryTracer.hasAllChildrenFinished() counted it as unfinished; and the timer never restarted. As a consequence, any idle transaction that i) waited for its children (i.e., all Android idle transactions, including ui.load and nav transactions) and ii) had an unfinished idle span was kept alive until its deadline (30 s by default), causing it to be reported as DEADLINE_EXCEEDED even though in most cases no actual work was keeping the transaction alive. **Current producers of idle spans** SentryTraced is the SDK's only producer of idle spans, so the effects mentioned above are limited to idle transactions that, prior to this commit, contained a span from SentryTraced. (The issue has been with SentryTraced from the beginning – see #2507). --- CHANGELOG.md | 1 + .../io/sentry/compose/SentryTracedTest.kt | 38 +++++++++++++-- .../src/main/java/io/sentry/SentryTracer.java | 18 ++++++- .../src/main/java/io/sentry/SpanOptions.java | 7 ++- .../test/java/io/sentry/SentryTracerTest.kt | 48 +++++++++++++++++++ 5 files changed, 105 insertions(+), 7 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 85bbfc57c8f..78bdf0a45cf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,7 @@ ### Fixes +- Idle spans (including those produced by `SentryTraced`) now let any idle parent transaction finish after the idle timeout rather than waiting for the deadline and reporting `DEADLINE_EXCEEDED` ([#6396](https://github.com/getsentry/sentry-java/pull/6396)). - Keep UI profiling running when `startProfiler` is called before a requested stop takes effect at the end of the current chunk ([#6291](https://github.com/getsentry/sentry-java/pull/6291)) - Before, the start call was ignored and the profiler still stopped at the end of the chunk, even in `TRACE` mode while sampled spans were active. On API 34 and lower, every later profile also stopped after one chunk. diff --git a/sentry-compose/src/androidUnitTest/kotlin/io/sentry/compose/SentryTracedTest.kt b/sentry-compose/src/androidUnitTest/kotlin/io/sentry/compose/SentryTracedTest.kt index 431ce297c46..935fb6933d5 100644 --- a/sentry-compose/src/androidUnitTest/kotlin/io/sentry/compose/SentryTracedTest.kt +++ b/sentry-compose/src/androidUnitTest/kotlin/io/sentry/compose/SentryTracedTest.kt @@ -31,6 +31,7 @@ import io.sentry.ITransaction import io.sentry.NoOpSpan import io.sentry.Sentry import io.sentry.SentryOptions +import io.sentry.SpanStatus import io.sentry.TransactionOptions import kotlin.test.assertFailsWith import org.junit.After @@ -446,8 +447,30 @@ class SentryTracedTest { assertThat(renderingTx.countSpans(OP_RENDER)).isEqualTo(0) } + @Test + fun `an idle transaction hosting a traced composable finishes after the idle timeout`() { + val tx = + initSentryAndStartTransaction( + "tx", + configureTransactionOptions = { transactionOptions -> + transactionOptions.idleTimeout = 1_000 + transactionOptions.isWaitForChildren = true + }, + ) + + rule.setContent { + ProvideSentrySpan(tx) { SentryTraced(tag = "product_info") { Box(Modifier.size(1.dp)) } } + } + tx.waitForSpanCount(OP_COMPOSE, 1) + + rule.waitUntil(timeoutMillis = 5_000) { tx.isFinished } + assertThat(tx.status).isEqualTo(SpanStatus.OK) + assertThat(tx.singleSpan(OP_PARENT_COMPOSITION).isFinished).isTrue() + } + private fun initSentryAndStartTransaction( name: String, + configureTransactionOptions: (TransactionOptions) -> Unit = {}, configureOptions: (SentryOptions) -> Unit = {}, ): ITransaction { lateinit var tx: ITransaction @@ -460,7 +483,7 @@ class SentryTracedTest { }, true, ) - tx = startBoundTransaction(name) + tx = startBoundTransaction(name, configureTransactionOptions) var boundTransaction: ITransaction? = null Sentry.configureScope { boundTransaction = it.transaction } assertThat(boundTransaction).isSameInstanceAs(tx) @@ -468,9 +491,16 @@ class SentryTracedTest { return tx } - private fun startBoundTransaction(name: String): ITransaction { - val transaction = - Sentry.startTransaction(name, "test", TransactionOptions().apply { isBindToScope = true }) + private fun startBoundTransaction( + name: String, + configureTransactionOptions: (TransactionOptions) -> Unit = {}, + ): ITransaction { + val transactionOptions = + TransactionOptions().apply { + isBindToScope = true + configureTransactionOptions(this) + } + val transaction = Sentry.startTransaction(name, "test", transactionOptions) Sentry.configureScope { it.setTransaction(transaction) } return transaction } diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 781cf51417e..96f5b183a50 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -469,7 +469,13 @@ private ISpan createChild( if (children.size() < scopes.getOptions().getMaxSpans()) { Objects.requireNonNull(parentSpanId, "parentSpanId is required"); Objects.requireNonNull(operation, "operation is required"); - cancelIdleTimer(); + + // When this transaction finishes, we want its idle spans to finish as well. We don't let idle + // spans cancel the idle timer b/c it would keep the transaction alive until its deadline. + if (!spanOptions.isIdle()) { + cancelIdleTimer(); + } + final Span span = new Span( this, @@ -762,10 +768,20 @@ private void updateBaggageValues(final @NotNull Baggage baggage) { return null; } + /** + * Returns true if no child span should keep this transaction from finishing. + * + *

Ignores idle spans. Including them would mean an idle transaction would never restart its + * idle timer once it had an unfinished idle span, causing the transaction to always live until + * its deadline. + */ private boolean hasAllChildrenFinished() { @NotNull final ListIterator iterator = this.children.listIterator(); while (iterator.hasNext()) { @NotNull final Span span = iterator.next(); + if (span.getOptions().isIdle()) { + continue; + } // This is used in the spanFinishCallback, when the span isn't finished, but has a finish // date if (!span.isFinished() && span.getFinishDate() == null) { diff --git a/sentry/src/main/java/io/sentry/SpanOptions.java b/sentry/src/main/java/io/sentry/SpanOptions.java index 69f93e00a9e..effe3449a53 100644 --- a/sentry/src/main/java/io/sentry/SpanOptions.java +++ b/sentry/src/main/java/io/sentry/SpanOptions.java @@ -48,8 +48,11 @@ public void setStartTimestamp(@Nullable SentryDate startTimestamp) { private boolean trimEnd = false; /** - * true if the span is considered idle and should be automatically finished when it's parent gets - * finished. + * `true` if the span is idle, in which case its transaction finishes it when the transaction + * finishes, with the transaction's status and end time. + * + *

Note: An unfinished idle span doesn't keep a transaction that waits for its children from + * finishing, but non-idle spans created under it do. */ private boolean isIdle = false; diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 95f19344243..3b97519229e 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -1204,6 +1204,54 @@ class SentryTracerTest { assertNull(transaction.idleTimeoutFuture) } + @Test + fun `when idle transaction has only an unfinished idle span, finishes the transaction and the idle span after the idle timeout`() { + val transaction = fixture.getSut(waitForChildren = true, idleTimeout = 50) + + val idleSpan = transaction.startChild("ui.load", null, SpanOptions().apply { isIdle = true }) + + await.untilAsserted { + verify(fixture.scopes).captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + } + assertThat(transaction.status).isEqualTo(SpanStatus.OK) + assertThat(idleSpan.isFinished).isTrue() + assertThat(idleSpan.status).isEqualTo(SpanStatus.OK) + } + + @Test + fun `when idle transaction has an idle span with a finished child, finishes the transaction after the idle timeout`() { + val transaction = fixture.getSut(waitForChildren = true, idleTimeout = 50) + val idleSpan = transaction.startChild("ui.load", null, SpanOptions().apply { isIdle = true }) + + idleSpan.startChild("ui.render").finish() + + await.untilAsserted { + verify(fixture.scopes).captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + } + assertThat(transaction.status).isEqualTo(SpanStatus.OK) + } + + @Test + fun `when idle transaction has an unfinished span under an idle span, does not finish the transaction until that span finishes`() { + val transaction = fixture.getSut(waitForChildren = true, idleTimeout = 50) + val idleSpan = transaction.startChild("ui.load", null, SpanOptions().apply { isIdle = true }) + val spanUnderIdleSpan = idleSpan.startChild("ui.render") + + transaction.startChild("op").finish() + Thread.sleep(200) + + assertThat(transaction.isFinished).isFalse() + verify(fixture.scopes, never()) + .captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + + spanUnderIdleSpan.finish() + + await.untilAsserted { + verify(fixture.scopes).captureTransaction(anyOrNull(), anyOrNull(), anyOrNull(), anyOrNull()) + } + assertThat(transaction.status).isEqualTo(SpanStatus.OK) + } + @Test fun `when trimEnd, trims idle transaction time to the latest child timestamp`() { val transaction =