Skip to content

Idle transactions containing SentryTraced spans wait for the deadline and finish as DEADLINE_EXCEEDED #6366

Open

Description

@0xadam-brown

Description

Idle transactions that contain SentryTraced spans (e.g. Nav3/Nav2 navigation transactions whose destination uses SentryTraced) never finish via the idle timeout. They stay open until the deadline timeout (30 s by default) and are force-finished with status DEADLINE_EXCEEDED.

Expected

An idle transaction (idleTimeout 3 s, deadlineTimeout 30 s, waitForChildren = true, trimEnd = true) finishes 3 s after its last child span finishes, with status OK, and is unbound from the scope. SentryTraced's idle bucket spans are closed when the transaction finishes and trimmed to their last child.

Actual

The transaction finishes exactly deadlineTimeout after it started, with status DEADLINE_EXCEEDED. Example from the Nav3 sample on an emulator (no other activity):

Expected Actual
/Confirmation starts 13:37:17.938 13:37:17.938
Last child span finishes ~13:37:18.47 ~13:37:18.47
Transaction finishes / sent ~13:37:21.5, OK 13:37:47.944, DEADLINE_EXCEEDED

Transactions without SentryTraced spans finish 3 s after their last child as expected.

Consequences:

  • Every affected transaction is reported as DEADLINE_EXCEEDED.
  • It's sent ~30 s late.
  • It stays bound to the scope for the whole 30 s, so unrelated spans created in that window attach to it and other transactions can't take the scope.
  • Reported duration looks roughly right because of trim-end.

Cause

  • SentryTraced groups its spans under two bucket spans (ui.compose.composition, ui.compose.rendering) created with SpanOptions.isIdle = true (SentryComposeTracing.kt, BucketSpans.getOrCreate). Idle spans are only closed by SentryTracer.finish() (SentryTracer.java, "auto-finish any idle spans first").
  • Creating any child cancels the idle timer (SentryTracer.createChild → cancelIdleTimer()).
  • When a child finishes, the idle timer is only rescheduled if hasAllChildrenFinished() is true. That check includes the still-open idle bucket spans, so it never passes.
  • Only the deadline timer remains, and onDeadlineTimeoutReached() force-finishes with DEADLINE_EXCEEDED.

Minimal repro (unit test, sentry module):

val transaction = fixture.getSut(waitForChildren = true, idleTimeout = 200)
val bucket = transaction.startChild("ui.compose.composition", null, SpanOptions().apply { isIdle = true })
bucket.startChild("ui.compose").finish()
Thread.sleep(1000)
// transaction.isFinished == false, transaction.isFinishTimerRunning == false

Existing idle-span tests in SentryTracerTest only finish the transaction explicitly via finish(), so this path isn't covered.

Proposed fix

In the child-finished callback in SentryTracer.createChild, reschedule the idle timer when all non-idle children have finished (e.g. a hasAllNonIdleChildrenFinished() helper), leaving the finish() check as is, since finish() closes idle spans just before it. SentryTraced is the only user of isIdle in the repo.

Add tests for the idle-timer path with an idle child, including a bucket that gets its first child later (timer resets).

Notes

  • Found while testing the Nav3 SentryNavEffect lifecycle stack (JAVA-785), but the cause is in sentry / sentry-compose, not navigation code.
  • Not yet reproduced on main; expected to reproduce there since the involved code isn't touched by that stack. Likely also affects Nav2 and any other idle transaction containing SentryTraced spans.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions