Skip to content

Commit 1baba8f

Browse files
committed
test(plugins): detect finished-span retention at agent teardown
Add a GC-driven detector that registers every finished span with a FinalizationRegistry and, at `agent.close()`, forces GC and asserts retention did not grow with the request count. It catches the failure mode where a captured async-context frame pins a finished span and its parent chain (#9227): a real leak retains one span per request and trips the cap, while a clean teardown holds only the few most-recent traces' roots. The bound is a small constant, not zero, because a span stores the frame it was created in (`span._store`), so a trace's spans form a `span -> store -> span` cycle that stays reachable until a later frame overwrites that async-context slot. Driving 100 sequential requests through the mock agent collects every root; a sweep of the http/http2 suites never retained more than two, so the cap is that measured maximum plus one slot of margin. The detector is inert without `--expose-gc`, so suites that do not pass the flag are unaffected. Refs: #9228
1 parent aaeb9a8 commit 1baba8f

4 files changed

Lines changed: 333 additions & 2 deletions

File tree

‎packages/dd-trace/test/plugins/agent.js‎

Lines changed: 12 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ const semifies = require('semifies')
1212

1313
const { assertObjectContains } = require('../../../../integration-tests/helpers')
1414
const { storage } = require('../../../datadog-core')
15+
const spanLeakDetector = require('./span-leak-detector')
1516

1617
// Modules that close over the previous `Config` / `TracerProxy` singletons.
1718
// Evicted whenever `agent.load`'s gate decides the tracer must rebuild.
@@ -428,6 +429,10 @@ module.exports = {
428429

429430
currentIntegrationName = getCurrentIntegrationName()
430431

432+
// Track finished spans for the retention assertion in `close()`. Idempotent
433+
// and inert without `--expose-gc`, so it is safe to arm on every load.
434+
spanLeakDetector.arm()
435+
431436
const tracerConfigJson = JSON.stringify(tracerConfig)
432437
if (
433438
!loaded ||
@@ -736,12 +741,17 @@ module.exports = {
736741

737742
tracer.llmobs.disable()
738743

739-
return /** @type {Promise<void>} */ (new Promise(resolve => {
744+
return /** @type {Promise<void>} */ (new Promise((resolve, reject) => {
740745
this.server.on('close', () => {
741746
this.server = null
742747
this.port = null
743748

744-
resolve()
749+
// Expectation callbacks (which can hold spans) were cleared above and
750+
// the server is closed, so no legitimate reference to a finished span
751+
// remains beyond the last trace's root (see the detector). Assert
752+
// retention did not grow with the request count, then resolve. A leak
753+
// rejects `close()`, surfacing as a suite teardown failure.
754+
spanLeakDetector.assertNoRetainedSpans().then(resolve, reject)
745755
})
746756
}))
747757
},

‎packages/dd-trace/test/plugins/plugin.spec.js‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -77,6 +77,50 @@ describe('Plugin', () => {
7777
assert.strictEqual(plugin._enabled, true)
7878
})
7979

80+
describe('enter', () => {
81+
it('should return the store written into storage carrying the span', () => {
82+
const parentSpan = { id: 'parent' }
83+
const span = { id: 'child' }
84+
85+
plugin = new GoodPlugin()
86+
87+
const entered = plugin.enter(span, { span: parentSpan })
88+
89+
assert.strictEqual(entered.span, span)
90+
// The returned object is the one written into storage, so a caller that
91+
// holds it can drop the finished span from any frame captured off it.
92+
assert.strictEqual(storage('legacy').getStore(), entered)
93+
})
94+
95+
it('should extend the current store when none is passed', () => {
96+
const span = { id: 'child' }
97+
98+
plugin = new GoodPlugin()
99+
100+
storage('legacy').run({ existing: true, span: undefined }, () => {
101+
const entered = plugin.enter(span)
102+
103+
assert.deepStrictEqual(entered, { existing: true, span })
104+
assert.strictEqual(storage('legacy').getStore(), entered)
105+
})
106+
})
107+
108+
it('should let a caller drop the finished span by nulling the returned store', () => {
109+
const span = { id: 'child' }
110+
111+
plugin = new GoodPlugin()
112+
const entered = plugin.enter(span, { span: undefined })
113+
114+
assert.strictEqual(entered.span, span)
115+
116+
// The release contract callers rely on at request finish: nulling the
117+
// returned store's span means a frame that captured it stops pinning it.
118+
entered.span = null
119+
120+
assert.strictEqual(entered.span, null)
121+
})
122+
})
123+
80124
it('should run binding transforms with an undefined current store', () => {
81125
class TestPlugin extends Plugin {
82126
static id = 'test'
Lines changed: 154 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,154 @@
1+
'use strict'
2+
3+
const assert = require('node:assert')
4+
5+
const { channel } = require('dc-polyfill')
6+
7+
const finishCh = channel('dd-trace:span:finish')
8+
9+
// A finished span's retention must not scale with the number of requests. The
10+
// classic violation is an async-context frame that captured a `{ ...store, span }`
11+
// object (see `Plugin#enter`): the frame outlives the request via any
12+
// never-released async resource and pins the finished span and its whole parent
13+
// chain, so retained spans grow one-per-request until the process OOMs
14+
// (DataDog/dd-trace-js#9227).
15+
//
16+
// This detector rides along on every suite that runs with `--expose-gc`: it
17+
// registers each finished span with a FinalizationRegistry and, at agent
18+
// teardown, forces GC and asserts retention did not grow with the request count.
19+
// It is a no-op without `--expose-gc`, so suites that do not pass the flag are
20+
// unaffected.
21+
//
22+
// Why the bound is a small constant, not zero: a span stores the async-context
23+
// frame it was created in (`span._store = storage('legacy').getHandle()`, see
24+
// `opentracing/span.js`). That frame is `{ ...parent, span }`, so a trace's spans
25+
// form a reference cycle (`span._store -> store -> span`) that stays reachable
26+
// until a *later* frame overwrites that async-context slot. At teardown the few
27+
// most-recently-created traces' frames have not been overwritten yet, so their
28+
// roots can still be alive. This is bounded by recency, not by request count:
29+
// driving 100 sequential requests through the mock-agent harness collects every
30+
// root (`retained === 0`), and a wide sweep of the http/http2 suites never
31+
// retained more than two (only the 1-2 requests a test makes right before its
32+
// teardown). A real leak like #9227 pins one span per request for the life of the
33+
// process, so `retained` climbs into the dozens or hundreds and trips the cap.
34+
35+
const gc = typeof global.gc === 'function' ? global.gc : undefined
36+
37+
/**
38+
* Number of forced-GC + drain cycles before giving up. FinalizationRegistry
39+
* callbacks are scheduled after collection and V8 may need more than one pass,
40+
* so poll rather than assert after a single GC.
41+
*/
42+
const MAX_GC_CYCLES = 10
43+
44+
/**
45+
* Upper bound on finished spans that may still be reachable at teardown without
46+
* indicating a leak. Benign retention is the handful of most-recent traces whose
47+
* async-context frames have not been overwritten yet (see above); a sweep of the
48+
* http/http2 suites topped out at two, so this is that measured maximum plus one
49+
* slot of margin. It is an absolute cap, not a per-request allowance: a #9227-style
50+
* leak retains one span per request and blows past it by orders of magnitude, so
51+
* the margin costs no detection power.
52+
*/
53+
const BASELINE_RETAINED = 3
54+
55+
class SpanLeakDetector {
56+
#registry
57+
#trackedCount = 0
58+
#collectedCount = 0
59+
#armed = false
60+
#onFinish = span => {
61+
this.#trackedCount++
62+
this.#registry.register(span)
63+
}
64+
65+
/**
66+
* Whether span-retention checking is possible in this process. Requires
67+
* `--expose-gc`; the detector is inert otherwise.
68+
*
69+
* @returns {boolean}
70+
*/
71+
get enabled () {
72+
return gc !== undefined
73+
}
74+
75+
/**
76+
* Start tracking finished spans. Idempotent so repeated `agent.load` calls in
77+
* one suite do not double-subscribe (which would inflate the tracked count and
78+
* leak the finish handler across load/close cycles).
79+
*
80+
* @returns {void}
81+
*/
82+
arm () {
83+
if (!this.enabled || this.#armed) return
84+
// Lazily create the registry so processes without `--expose-gc` never build
85+
// one. The callback only counts; it must not retain the span.
86+
this.#registry ??= new FinalizationRegistry(() => {
87+
this.#collectedCount++
88+
})
89+
finishCh.subscribe(this.#onFinish)
90+
this.#armed = true
91+
}
92+
93+
/**
94+
* Force GC and assert that finished-span retention has not grown with the
95+
* request count. Call once the tracer has flushed and no test-owned reference
96+
* to a span remains (i.e. at agent teardown, after expectation callbacks are
97+
* cleared). Up to {@link BASELINE_RETAINED} spans may survive (the few
98+
* most-recent traces' roots, still held by their `span._store` cycle); more
99+
* than that means a tracer-owned structure is pinning finished spans
100+
* one-per-request. Resets counters so the next suite starts clean. No-op when
101+
* the detector is inert or nothing was tracked.
102+
*
103+
* @returns {Promise<void>}
104+
*/
105+
async assertNoRetainedSpans () {
106+
if (!this.#armed) return
107+
108+
finishCh.unsubscribe(this.#onFinish)
109+
this.#armed = false
110+
111+
if (this.#trackedCount === 0) {
112+
this.#reset()
113+
return
114+
}
115+
116+
// Let any pending flush / microtasks settle, then force GC and give the
117+
// registry callbacks a turn. Repeat until retention is within the baseline or
118+
// the cycle budget is spent (polling because FinalizationRegistry callbacks
119+
// run after collection and V8 may need more than one pass).
120+
for (
121+
let cycle = 0;
122+
cycle < MAX_GC_CYCLES && this.#trackedCount - this.#collectedCount > BASELINE_RETAINED;
123+
cycle++
124+
) {
125+
await new Promise(resolve => setImmediate(resolve))
126+
gc()
127+
}
128+
await new Promise(resolve => setImmediate(resolve))
129+
130+
const retained = this.#trackedCount - this.#collectedCount
131+
const tracked = this.#trackedCount
132+
this.#reset()
133+
134+
assert.ok(
135+
retained <= BASELINE_RETAINED,
136+
`${retained} of ${tracked} finished spans were still reachable after flush + GC ` +
137+
`(at most ${BASELINE_RETAINED} may survive as recently-created traces whose async-context ` +
138+
'frames have not been overwritten yet). Retention is growing with the request count — a ' +
139+
'tracer-owned structure is pinning finished spans, commonly an async-context frame that ' +
140+
'captured a `{ ...store, span }` object without a matching `releaseSpan` ' +
141+
'(see DataDog/dd-trace-js#9227).'
142+
)
143+
}
144+
145+
#reset () {
146+
this.#trackedCount = 0
147+
this.#collectedCount = 0
148+
}
149+
}
150+
151+
module.exports = new SpanLeakDetector()
152+
// Exposed for the detector's own spec, which asserts both the retained and the
153+
// freed outcome against fresh instances without a real agent teardown.
154+
module.exports.SpanLeakDetector = SpanLeakDetector
Lines changed: 123 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,123 @@
1+
'use strict'
2+
3+
const assert = require('node:assert')
4+
5+
const { describe, it } = require('mocha')
6+
const { channel } = require('dc-polyfill')
7+
8+
const { SpanLeakDetector } = require('./span-leak-detector')
9+
10+
const finishCh = channel('dd-trace:span:finish')
11+
12+
if (typeof global.gc !== 'function') {
13+
throw new Error('span-leak-detector.spec.js requires --expose-gc')
14+
}
15+
16+
// Pins the retention contract the agent-teardown check relies on: retention that
17+
// grows with the request count must be reported as a leak, while the small,
18+
// recency-bounded baseline (the few most-recent traces whose async-context frames
19+
// have not been overwritten yet) must pass. The detector tolerates up to
20+
// BASELINE_RETAINED (3) survivors — a measured maximum of two across the http
21+
// suites plus one slot of margin — so the boundary cases below pin 3 (accepted)
22+
// and 4 (the first rejected). Uses fresh detector instances (not the agent
23+
// singleton) so every outcome can be asserted without a real teardown.
24+
25+
const BASELINE_RETAINED = 3
26+
27+
async function forceGc () {
28+
for (let i = 0; i < 10; i++) {
29+
await new Promise(resolve => setImmediate(resolve))
30+
global.gc()
31+
}
32+
}
33+
34+
/**
35+
* Publish `count` finish events for spans held by strong references, mirroring
36+
* finished spans pinned by a never-released async-context frame. The references
37+
* are returned so the caller keeps them live across the assertion.
38+
*
39+
* @param {number} count
40+
* @returns {Array<{ _name: string }>}
41+
*/
42+
function publishRetained (count) {
43+
const spans = []
44+
for (let i = 0; i < count; i++) {
45+
const span = { _name: `leaked.span.${i}` }
46+
spans.push(span)
47+
finishCh.publish(span)
48+
}
49+
return spans
50+
}
51+
52+
describe('span-leak-detector', () => {
53+
it('tolerates retention at the baseline (the recency-bounded roots)', async () => {
54+
const detector = new SpanLeakDetector()
55+
detector.arm()
56+
57+
// Exactly BASELINE_RETAINED survivors mirror the last few traces' roots still
58+
// held by their `span._store` cycle at teardown; bounded, not a leak.
59+
const baselineSpans = publishRetained(BASELINE_RETAINED)
60+
61+
await detector.assertNoRetainedSpans()
62+
assert.strictEqual(baselineSpans.length, BASELINE_RETAINED)
63+
})
64+
65+
it('reports a leak when retention exceeds the baseline by one', async () => {
66+
const detector = new SpanLeakDetector()
67+
detector.arm()
68+
69+
// One past the baseline is the smallest retention that indicates growth with
70+
// the request count rather than the bounded recency window.
71+
const retainedSpans = publishRetained(BASELINE_RETAINED + 1)
72+
73+
await assert.rejects(
74+
() => detector.assertNoRetainedSpans(),
75+
new RegExp(`${BASELINE_RETAINED + 1} of ${BASELINE_RETAINED + 1} finished spans were still reachable`)
76+
)
77+
78+
// References stay live through the assertion, mirroring a captured frame.
79+
assert.strictEqual(retainedSpans.length, BASELINE_RETAINED + 1)
80+
})
81+
82+
it('reports no retention when nothing holds the finished span', async () => {
83+
const detector = new SpanLeakDetector()
84+
detector.arm()
85+
86+
// Publish a span held by nothing so no reference survives to the assertion.
87+
;(() => finishCh.publish({ _name: 'collectable.span' }))()
88+
89+
await forceGc()
90+
await detector.assertNoRetainedSpans()
91+
})
92+
93+
it('is a no-op when armed but nothing was tracked', async () => {
94+
const detector = new SpanLeakDetector()
95+
detector.arm()
96+
97+
await detector.assertNoRetainedSpans()
98+
})
99+
100+
it('is a no-op when never armed', async () => {
101+
const detector = new SpanLeakDetector()
102+
103+
await detector.assertNoRetainedSpans()
104+
})
105+
106+
it('does not double-count finished spans when armed twice', async () => {
107+
const detector = new SpanLeakDetector()
108+
detector.arm()
109+
detector.arm()
110+
111+
// Spans must be counted once each, not once per arm() call — otherwise a
112+
// repeated agent.load in one suite would inflate the count and leak the finish
113+
// handler. Publish one past the baseline so the (correct) count still trips
114+
// the assertion; a double-count would report twice as many.
115+
const retainedSpans = publishRetained(BASELINE_RETAINED + 1)
116+
117+
await assert.rejects(
118+
() => detector.assertNoRetainedSpans(),
119+
new RegExp(`${BASELINE_RETAINED + 1} of ${BASELINE_RETAINED + 1} finished spans were still reachable`)
120+
)
121+
assert.strictEqual(retainedSpans.length, BASELINE_RETAINED + 1)
122+
})
123+
})

0 commit comments

Comments
 (0)