core: Idle span ends early because _restartChildSpanTimeout writes its handle to _idleTimeoutID #23404

Is there an existing issue for this?

• I have checked for existing issues https://github.com/getsentry/sentry-javascript/issues
• I have reviewed the documentation https://docs.sentry.io/
• I am using the latest SDK release https://github.com/getsentry/sentry-javascript/releases

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/browser

SDK Version

10.70.0

Framework Version

No response

Link to Sentry event

No response

Reproduction Example/SDK Setup

The defect is in @sentry/core's startIdleSpan, so the shortest reproduction is a unit test in this repo.
Save as packages/core/test/lib/tracing/idlespan-repro.test.ts and run
cd packages/core && yarn vitest run test/lib/tracing/idlespan-repro.test.ts:

import { beforeEach, describe, expect, it, vi } from 'vitest';
import { getClient, setCurrentClient, spanToJSON, startInactiveSpan } from '../../../src';
import { startIdleSpan } from '../../../src/tracing/idleSpan';
import { getDefaultTestClientOptions, TestClient } from '../../mocks/client';
import { resetGlobals } from '../../testutils';

const dsn = 'https://123@sentry.io/42';

describe('idle span deadline after idleSpanEnableAutoFinish', () => {
  beforeEach(() => {
    vi.useFakeTimers();
    resetGlobals();
    const client = new TestClient(getDefaultTestClientOptions({ dsn, tracesSampleRate: 1 }));
    setCurrentClient(client);
    client.init();
  });

  it('keeps the idle span open until idleTimeout after the LAST child ends', () => {
    const idleSpan = startIdleSpan({ name: 'pageload' }, { disableAutoFinish: true, finalTimeout: 99_000 });
    const idleSpanId = idleSpan.spanContext().spanId;

    // A child is in flight when the page-load signal arrives (readyState 'interactive').
    const childA = startInactiveSpan({ name: 'child-A' });

    vi.advanceTimersByTime(500);
    getClient()!.emit('idleSpanEnableAutoFinish', idleSpan);

    vi.advanceTimersByTime(700);            // t=1200
    childA!.end();                          // idle deadline should now be t=2200

    vi.advanceTimersByTime(299);            // t=1499
    console.log('t=1499 pageload ended?', spanToJSON(idleSpan).end_timestamp !== undefined);

    vi.advanceTimersByTime(2);              // t=1501
    console.log('t=1501 pageload ended?', spanToJSON(idleSpan).end_timestamp !== undefined);

    // A late child starting inside the lost window, still 400ms before the correct t=2200 deadline.
    vi.advanceTimersByTime(299);            // t=1800
    const childB = startInactiveSpan({ name: 'child-B' });
    console.log('t=1800 child-B attached to pageload?', spanToJSON(childB!).parent_span_id === idleSpanId);
    console.log('  child-A was attached to pageload?', spanToJSON(childA!).parent_span_id === idleSpanId);

    expect(spanToJSON(idleSpan).end_timestamp).toBeUndefined();
  });
});

Steps to Reproduce

1. Check out develop (reproduced on b0b09f8) or 10.70.0, run yarn && yarn build:dev.
2. Add the test file from the section above and run it.
3. Or read packages/core/src/tracing/idleSpan.ts directly:
   • :99 declares _idleTimeoutID
   • :102 declares _childSpanTimeoutID
   • :230 _restartIdleTimeout does _idleTimeoutID = setTimeout(...)
   • :243 _restartChildSpanTimeout also does _idleTimeoutID = setTimeout(...)
_childSpanTimeoutID is declared and read (:219) but never assigned anywhere:
     grep -n '_childSpanTimeoutID' packages/core/src/tracing/idleSpan.ts
4. In the browser this is reached through the pageload span: browserTracingIntegration.ts:412 passes
   disableAutoFinish: isPageloadSpan, and :423-424 emit idleSpanEnableAutoFinish as soon as
   document.readyState is 'interactive' or 'complete' — often while fetch/xhr child spans are in flight.
   The handler at idleSpan.ts:392-395 calls _restartIdleTimeout() and then, when activities.size is
   non-zero, _restartChildSpanTimeout(), which overwrites the idle timer's handle.

Expected Result

The idle span's deadline is measured from the end of the last child span. With idleTimeout at its default
1000ms and the last child ending at t=1200, the span should stay open until t=2200, so a child started at
t=1800 is still part of the pageload transaction:

t=1499 pageload ended? false
t=1501 pageload ended? false
t=1800 child-B attached to pageload? true
child-A was attached to pageload? true

Actual Result

The span ends at t≈1500 — 1000ms after the auto-finish signal at t=500, not 1000ms after the last child ended
at t=1200. A child started at t=1800, still 400ms before the correct deadline, is no longer attached to the
pageload span:

t=1499 pageload ended? false
t=1501 pageload ended? true <-- ends here
t=1800 child-B attached to pageload? false <-- dropped
child-A was attached to pageload? true <-- control

Additional Context

Root cause

_restartChildSpanTimeout (idleSpan.ts:241-249) arms the child-span timeout but stores the handle in
_idleTimeoutID at :243 instead of _childSpanTimeoutID. Two consequences:

1. _childSpanTimeoutID is never assigned, so _cancelChildSpanTimeout() (:218-223) is dead code at both of
   its call sites (:242 and :279).
2. _restartChildSpanTimeout overwrites _idleTimeoutID without clearing what it pointed at, orphaning an
   armed idle timer that nothing can cancel. It later fires with activities.size === 0 && _autoFinishAllowed, ending the span early.

In the repro: _restartIdleTimeout() at t=500 arms T_idle for t=1500 in _idleTimeoutID; the immediately
following _restartChildSpanTimeout() overwrites that handle, so when _popActivity runs at t=1200 its
_cancelIdleTimeout() cancels the child timer and arms a correct T_idle2 for t=2200 — but the orphaned
T_idle from t=500 is still armed and fires first.

The build output confirms the variable is never written: rollup tree-shook it away entirely.

$ grep -c '_childSpanTimeoutID' packages/core/build/cjs/tracing/idleSpan.js
0
$ grep -c '_cancelChildSpanTimeout' packages/core/build/cjs/tracing/idleSpan.js
0
$ grep -n '_idleTimeoutID = setTimeout' packages/core/build/cjs/tracing/idleSpan.js
95: _idleTimeoutID = setTimeout(() => {
103: _idleTimeoutID = setTimeout(() => {

Also present in 10.70.0, at idleSpan.ts:235 and :248.

Scope

• Only the idleSpanEnableAutoFinish path (:392-395) is harmful. The other _restartChildSpanTimeout caller,
  _pushActivity (:262), is harmless because _cancelIdleTimeout() already ran at :256 — which is why no
  existing test catches this.
• Harm requires that every activity in flight at signal time ends before signalTime + idleTimeout. If any is
  still open when the orphan fires, the activities.size === 0 guard makes it a no-op.
• The lost window is lastChildEnd - signalTime, i.e. 0..idleTimeout — 700ms in this repro, not a flat 1000ms.
• Transaction duration is unaffected: the end timestamp is trimmed to the last child's end either way. The
  damage is child spans that start in the lost window being dropped, and they are not counted in
  sentry.idle_span_discarded_spans either.
• childSpanTimeout itself still works today, but only by accident via _cancelIdleTimeout. This report is
  about the early idle-span end, not about childSpanTimeout being broken.

Suggested fix

One line — idleSpan.ts:243 becomes _childSpanTimeoutID = setTimeout(. _cancelChildSpanTimeout() at :242
and :279 then do their job. Happy to open a PR with a regression test in
packages/core/test/lib/tracing/idleSpan.test.ts.

Priority

_{React with 👍 to help prioritize this issue. Please use comments to provide useful context, avoiding +1 or me too, to help us triage it.}