Skip to content

Commit f3c5706

Browse files
szegediclaude
szegedi
and
claude
authored
fix(profiling): stale ProfilingContext cache causing missing trace endpoint labels (#7786)
TracingPlugin.startSpan() calls storage.enterWith({span}) immediately on span creation, before the plugin calls addRequestTags() to set span.type='web'. The first enterCh event therefore fires with span.type unset, causing #getProfilingContext to compute webTags=undefined and cache that result on the span. When the span is re-activated moments later (with span.type='web' already set) the stale cache is returned and webTags stays undefined for the entire request, so no trace endpoint labels appear in the CPU profile. Fix: skip writing the cache when endpointCollectionEnabled is true, webTags is undefined, *and* the span's type is not yet set. On the next activation the context is recomputed; once span.type='web' is known webTags is found and the result is cached normally. This affects both the ACF path (pprof.time.setContext per activation) and the non-ACF path (_currentContext.ref mutation), so the fix lives in #getProfilingContext which is shared by both. Co-authored-by: Claude Sonnet 4.6 <[email protected]>
1 parent 6dac2bd commit f3c5706

File tree

2 files changed

+139
-1
lines changed

2 files changed

+139
-1
lines changed

‎packages/dd-trace/src/profiling/profilers/wall.js‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -290,7 +290,15 @@ class NativeWallProfiler {
290290
}
291291

292292
profilingContext = { spanId, rootSpanId, webTags }
293-
span[ProfilingContext] = profilingContext
293+
// Don't cache if endpoint collection is enabled and webTags is undefined but
294+
// the span's type hasn't been set yet. TracingPlugin.startSpan() calls
295+
// enterWith() before the plugin sets span.type='web' via addRequestTags(),
296+
// so the first enterCh event fires before the type is known. Without this
297+
// guard we'd cache webTags=undefined and then serve that stale value on the
298+
// subsequent activation (when span.type='web' is already set).
299+
if (!this.#endpointCollectionEnabled || webTags !== undefined || context._tags['span.type']) {
300+
span[ProfilingContext] = profilingContext
301+
}
294302
}
295303
return profilingContext
296304
}

‎packages/dd-trace/test/profiling/profilers/wall.spec.js‎

Lines changed: 130 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
const assert = require('node:assert/strict')
44

55
const { describe, it, beforeEach } = require('mocha')
6+
const dc = require('dc-polyfill')
67
const proxyquire = require('proxyquire')
78
const sinon = require('sinon')
89

@@ -27,6 +28,7 @@ describe('profilers/native/wall', () => {
2728
kSampleCount: 0,
2829
NON_JS_THREADS_FUNCTION_NAME: 'Non JS threads activity',
2930
},
31+
getState: sinon.stub().returns({ 0: 0 }),
3032
getMetrics: sinon.stub().returns({
3133
totalAsyncContextCount: 0,
3234
usedAsyncContextCount: 0,
@@ -293,4 +295,132 @@ describe('profilers/native/wall', () => {
293295
'trace endpoint': 'GET /foo/bar',
294296
})
295297
})
298+
299+
describe('webTags caching in getProfilingContext', () => {
300+
// TracingPlugin.startSpan() calls storage.enterWith({span}) immediately on span
301+
// creation, before the plugin calls addRequestTags() to set span.type='web'.
302+
// This means the first enterCh event fires with span.type unset. The profiler
303+
// must not cache webTags=undefined from that first event, or the subsequent
304+
// activation (with span.type='web' already set) would incorrectly use the
305+
// stale cache and never produce trace endpoint labels.
306+
let enterCh
307+
let currentStore
308+
let localPprof
309+
let WallProfiler
310+
311+
beforeEach(() => {
312+
enterCh = dc.channel('dd-trace:storage:enter')
313+
currentStore = null
314+
315+
// Fresh setContext stub so we can track calls independently per test.
316+
localPprof = {
317+
...pprof,
318+
time: {
319+
...pprof.time,
320+
setContext: sinon.stub(),
321+
},
322+
}
323+
324+
WallProfiler = proxyquire('../../../src/profiling/profilers/wall', {
325+
'@datadog/pprof': localPprof,
326+
'../../../../datadog-core': { storage: () => ({ getStore: () => currentStore }) },
327+
})
328+
})
329+
330+
function makeWebSpan () {
331+
const tags = {}
332+
const spanId = {}
333+
const ctx = { _tags: tags, _spanId: spanId, _parentId: null, _trace: { started: [] } }
334+
const span = { context: () => ctx }
335+
ctx._trace.started.push(span)
336+
return { span, tags, spanId }
337+
}
338+
339+
function makeChildSpan (webSpanId, webSpan) {
340+
const tags = { 'span.type': 'router' }
341+
const spanId = {}
342+
const ctx = { _tags: tags, _spanId: spanId, _parentId: webSpanId, _trace: { started: [webSpan] } }
343+
const span = { context: () => ctx }
344+
ctx._trace.started.push(span)
345+
return { span, tags }
346+
}
347+
348+
it('should recompute webTags on re-activation after span.type is set (ACF path)', () => {
349+
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
350+
const profiler = new WallProfiler({
351+
endpointCollectionEnabled: true,
352+
codeHotspotsEnabled: true,
353+
asyncContextFrameEnabled: true,
354+
})
355+
profiler.start()
356+
357+
// First activation: span.type not yet set → webTags cannot be determined
358+
currentStore = { span: webSpan }
359+
enterCh.publish()
360+
assert.strictEqual(localPprof.time.setContext.getCall(0).args[0].webTags, undefined)
361+
362+
// Plugin sets span.type='web' (simulating addRequestTags)
363+
webSpanTags['span.type'] = 'web'
364+
365+
// Second activation: span.type='web' → webTags must now be the tags object
366+
enterCh.publish()
367+
assert.strictEqual(localPprof.time.setContext.getCall(1).args[0].webTags, webSpanTags)
368+
369+
profiler.stop()
370+
})
371+
372+
it('should recompute webTags on re-activation after span.type is set (non-ACF path)', () => {
373+
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
374+
const profiler = new WallProfiler({
375+
endpointCollectionEnabled: true,
376+
codeHotspotsEnabled: true,
377+
asyncContextFrameEnabled: false,
378+
})
379+
profiler.start()
380+
381+
// In non-ACF mode, start() calls #setNewContext() which calls setContext({ref:{}}).
382+
// Subsequent #enter() calls mutate the .ref property of that holder in place.
383+
const contextHolder = localPprof.time.setContext.getCall(0).args[0]
384+
385+
// First activation: span.type not yet set → webTags=undefined
386+
currentStore = { span: webSpan }
387+
enterCh.publish()
388+
assert.strictEqual(contextHolder.ref.webTags, undefined)
389+
390+
// Plugin sets span.type='web'
391+
webSpanTags['span.type'] = 'web'
392+
393+
// Second activation: must recompute and find webTags
394+
enterCh.publish()
395+
assert.strictEqual(contextHolder.ref.webTags, webSpanTags)
396+
397+
profiler.stop()
398+
})
399+
400+
it('should propagate webTags to child spans after web span type is set (ACF path)', () => {
401+
const { span: webSpan, tags: webSpanTags, spanId: webSpanId } = makeWebSpan()
402+
const { span: childSpan } = makeChildSpan(webSpanId, webSpan)
403+
404+
const profiler = new WallProfiler({
405+
endpointCollectionEnabled: true,
406+
codeHotspotsEnabled: true,
407+
asyncContextFrameEnabled: true,
408+
})
409+
profiler.start()
410+
411+
// Activate web span twice (first without type, then with type)
412+
currentStore = { span: webSpan }
413+
enterCh.publish()
414+
webSpanTags['span.type'] = 'web'
415+
enterCh.publish()
416+
417+
// Now activate the child span — it must inherit webTags via parent walk
418+
currentStore = { span: childSpan }
419+
enterCh.publish()
420+
const childCtx = localPprof.time.setContext.lastCall.args[0]
421+
assert.strictEqual(childCtx.webTags, webSpanTags)
422+
423+
profiler.stop()
424+
})
425+
})
296426
})

0 commit comments

Comments
 (0)