Skip to content

Commit 3c57767

Browse files
authored
fix(profiler): Remove endpoint recomputation, promptly observe tag updates (#7864)
1 parent 64890d7 commit 3c57767

3 files changed

Lines changed: 116 additions & 29 deletions

File tree

packages/dd-trace/src/opentracing/span.js

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@ const integrationCounters = {
3535

3636
const startCh = channel('dd-trace:span:start')
3737
const finishCh = channel('dd-trace:span:finish')
38+
const tagsUpdateCh = channel('dd-trace:span:tags:update')
3839

3940
function getIntegrationCounter (event, integration) {
4041
const counters = integrationCounters[event]
@@ -399,6 +400,10 @@ class DatadogSpan {
399400
tagger.add(this._spanContext._tags, keyValuePairs)
400401

401402
this._prioritySampler.sample(this, false)
403+
404+
if (tagsUpdateCh.hasSubscribers) {
405+
tagsUpdateCh.publish(this)
406+
}
402407
}
403408
}
404409

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

Lines changed: 19 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ const TRACE_ENDPOINT_LABEL = 'trace endpoint'
2020
let beforeCh
2121
const enterCh = dc.channel('dd-trace:storage:enter')
2222
const spanFinishCh = dc.channel('dd-trace:span:finish')
23+
const tagsUpdateCh = dc.channel('dd-trace:span:tags:update')
2324
const profilerTelemetryMetrics = telemetryMetrics.manager.namespace('profilers')
2425

2526
const ProfilingContext = Symbol('NativeWallProfiler.ProfilingContext')
@@ -122,6 +123,7 @@ class NativeWallProfiler {
122123
// Bind these to this so they can be used as callbacks
123124
#boundEnter = this.#enter.bind(this)
124125
#boundSpanFinished = this.#spanFinished.bind(this)
126+
#boundSpanTagsUpdated = this.#spanTagsUpdated.bind(this)
125127
#boundGenerateLabels = this._generateLabels.bind(this)
126128

127129
get type () { return 'wall' }
@@ -201,6 +203,9 @@ class NativeWallProfiler {
201203
}
202204
enterCh.subscribe(this.#boundEnter)
203205
spanFinishCh.subscribe(this.#boundSpanFinished)
206+
if (this.#endpointCollectionEnabled) {
207+
tagsUpdateCh.subscribe(this.#boundSpanTagsUpdated)
208+
}
204209
}
205210
}
206211

@@ -287,15 +292,7 @@ class NativeWallProfiler {
287292
}
288293

289294
profilingContext = { spanId, rootSpanId, webTags }
290-
// Don't cache if endpoint collection is enabled and webTags is undefined but
291-
// the span's type hasn't been set yet. TracingPlugin.startSpan() calls
292-
// enterWith() before the plugin sets span.type='web' via addRequestTags(),
293-
// so the first enterCh event fires before the type is known. Without this
294-
// guard we'd cache webTags=undefined and then serve that stale value on the
295-
// subsequent activation (when span.type='web' is already set).
296-
if (!this.#endpointCollectionEnabled || webTags !== undefined || context._tags['span.type']) {
297-
span[ProfilingContext] = profilingContext
298-
}
295+
span[ProfilingContext] = profilingContext
299296
}
300297
return profilingContext
301298
}
@@ -314,6 +311,16 @@ class NativeWallProfiler {
314311
}
315312
}
316313

314+
#spanTagsUpdated (span) {
315+
if (!this.#started) return
316+
const profilingContext = span[ProfilingContext]
317+
if (profilingContext === undefined || profilingContext.webTags !== undefined) return
318+
const tags = span.context()._tags
319+
if (isWebServerSpan(tags)) {
320+
profilingContext.webTags = tags
321+
}
322+
}
323+
317324
#reportV8bug (maybeBug) {
318325
const tag = `v8_profiler_bug_workaround_enabled:${this.#v8ProfilerBugWorkaroundEnabled}`
319326
const metric = `v8_cpu_profiler${maybeBug ? '_maybe' : ''}_stuck_event_loop`
@@ -352,6 +359,9 @@ class NativeWallProfiler {
352359
}
353360
enterCh.unsubscribe(this.#boundEnter)
354361
spanFinishCh.unsubscribe(this.#boundSpanFinished)
362+
if (this.#endpointCollectionEnabled) {
363+
tagsUpdateCh.unsubscribe(this.#boundSpanTagsUpdated)
364+
}
355365
this._profilerState = undefined
356366
}
357367
this.#started = false

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

Lines changed: 92 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -300,16 +300,18 @@ describe('profilers/native/wall', () => {
300300
// TracingPlugin.startSpan() calls storage.enterWith({span}) immediately on span
301301
// creation, before the plugin calls addRequestTags() to set span.type='web'.
302302
// 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.
303+
// caches the profilingContext with webTags=undefined. When addRequestTags()
304+
// later sets span.type='web', the dd-trace:span:tags:update channel fires and
305+
// the profiler updates the cached context's webTags in place.
306306
let enterCh
307+
let tagsUpdateCh
307308
let currentStore
308309
let localPprof
309310
let WallProfiler
310311

311312
beforeEach(() => {
312313
enterCh = dc.channel('dd-trace:storage:enter')
314+
tagsUpdateCh = dc.channel('dd-trace:span:tags:update')
313315
currentStore = null
314316

315317
// Fresh setContext stub so we can track calls independently per test.
@@ -351,7 +353,7 @@ describe('profilers/native/wall', () => {
351353
return { span, tags }
352354
}
353355

354-
it('should recompute webTags on re-activation after span.type is set (ACF path)', () => {
356+
it('should resolve webTags via tags update channel (ACF path)', () => {
355357
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
356358
const profiler = new WallProfiler({
357359
endpointCollectionEnabled: true,
@@ -360,22 +362,26 @@ describe('profilers/native/wall', () => {
360362
})
361363
profiler.start()
362364

363-
// First activation: span.type not yet set → webTags cannot be determined
365+
// First activation: span.type not yet set → webTags cached as undefined
364366
currentStore = { span: webSpan }
365367
enterCh.publish()
366-
assert.strictEqual(localPprof.time.setContext.getCall(0).args[0].webTags, undefined)
368+
const ctx0 = localPprof.time.setContext.getCall(0).args[0]
369+
assert.strictEqual(ctx0.webTags, undefined)
367370

368-
// Plugin sets span.type='web' (simulating addRequestTags)
371+
// Re-activation alone won't resolve webTags — cached context returned as-is
369372
webSpanTags['span.type'] = 'web'
370-
371-
// Second activation: span.type='web' → webTags must now be the tags object
372373
enterCh.publish()
373-
assert.strictEqual(localPprof.time.setContext.getCall(1).args[0].webTags, webSpanTags)
374+
assert.strictEqual(localPprof.time.setContext.getCall(1).args[0], ctx0)
375+
assert.strictEqual(ctx0.webTags, undefined)
376+
377+
// The tags update channel resolves it in place — no re-activation needed
378+
tagsUpdateCh.publish(webSpan)
379+
assert.strictEqual(ctx0.webTags, webSpanTags)
374380

375381
profiler.stop()
376382
})
377383

378-
it('should recompute webTags on re-activation after span.type is set (non-ACF path)', () => {
384+
it('should resolve webTags via tags update channel (non-ACF path)', () => {
379385
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
380386
const profiler = new WallProfiler({
381387
endpointCollectionEnabled: true,
@@ -384,26 +390,26 @@ describe('profilers/native/wall', () => {
384390
})
385391
profiler.start()
386392

387-
// In non-ACF mode, start() calls #setNewContext() which calls setContext({ref:{}}).
388-
// Subsequent #enter() calls mutate the .ref property of that holder in place.
389393
const contextHolder = localPprof.time.setContext.getCall(0).args[0]
390394

391-
// First activation: span.type not yet set → webTags=undefined
395+
// First activation: span.type not yet set → webTags cached as undefined
392396
currentStore = { span: webSpan }
393397
enterCh.publish()
394398
assert.strictEqual(contextHolder.ref.webTags, undefined)
395399

396-
// Plugin sets span.type='web'
400+
// Re-activation alone won't resolve webTags — cached context returned as-is
397401
webSpanTags['span.type'] = 'web'
398-
399-
// Second activation: must recompute and find webTags
400402
enterCh.publish()
403+
assert.strictEqual(contextHolder.ref.webTags, undefined)
404+
405+
// The tags update channel resolves it in place through the ref
406+
tagsUpdateCh.publish(webSpan)
401407
assert.strictEqual(contextHolder.ref.webTags, webSpanTags)
402408

403409
profiler.stop()
404410
})
405411

406-
it('should propagate webTags to child spans after web span type is set (ACF path)', () => {
412+
it('should propagate webTags to child spans after tags update resolves parent (ACF path)', () => {
407413
const { span: webSpan, tags: webSpanTags, spanId: webSpanId } = makeWebSpan()
408414
const { span: childSpan } = makeChildSpan(webSpanId, webSpan)
409415

@@ -414,11 +420,11 @@ describe('profilers/native/wall', () => {
414420
})
415421
profiler.start()
416422

417-
// Activate web span twice (first without type, then with type)
423+
// Activate web span, then resolve via tags update channel
418424
currentStore = { span: webSpan }
419425
enterCh.publish()
420426
webSpanTags['span.type'] = 'web'
421-
enterCh.publish()
427+
tagsUpdateCh.publish(webSpan)
422428

423429
// Now activate the child span — it must inherit webTags via parent walk
424430
currentStore = { span: childSpan }
@@ -428,5 +434,71 @@ describe('profilers/native/wall', () => {
428434

429435
profiler.stop()
430436
})
437+
438+
it('should not update webTags for non-web spans via tags update channel', () => {
439+
const { span: webSpan, spanId: webSpanId } = makeWebSpan()
440+
const { span: childSpan } = makeChildSpan(webSpanId, webSpan)
441+
442+
const profiler = new WallProfiler({
443+
endpointCollectionEnabled: true,
444+
codeHotspotsEnabled: true,
445+
asyncContextFrameEnabled: true,
446+
})
447+
profiler.start()
448+
449+
// Activate child span (router type)
450+
currentStore = { span: childSpan }
451+
enterCh.publish()
452+
const childCtx = localPprof.time.setContext.lastCall.args[0]
453+
454+
// Tags update on child span should not set webTags (it's not a web span)
455+
tagsUpdateCh.publish(childSpan)
456+
assert.strictEqual(childCtx.webTags, undefined)
457+
458+
profiler.stop()
459+
})
460+
461+
it('should ignore tags update for spans without cached profiling context', () => {
462+
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
463+
const profiler = new WallProfiler({
464+
endpointCollectionEnabled: true,
465+
codeHotspotsEnabled: true,
466+
asyncContextFrameEnabled: true,
467+
})
468+
profiler.start()
469+
470+
// Publish tags update before the span is ever activated — no cached context
471+
webSpanTags['span.type'] = 'web'
472+
tagsUpdateCh.publish(webSpan)
473+
474+
// No setContext call beyond the initial setup
475+
sinon.assert.notCalled(localPprof.time.setContext)
476+
477+
profiler.stop()
478+
})
479+
480+
it('should not update already-resolved webTags via tags update channel', () => {
481+
const { span: webSpan, tags: webSpanTags } = makeWebSpan()
482+
webSpanTags['span.type'] = 'web'
483+
484+
const profiler = new WallProfiler({
485+
endpointCollectionEnabled: true,
486+
codeHotspotsEnabled: true,
487+
asyncContextFrameEnabled: true,
488+
})
489+
profiler.start()
490+
491+
// Activate with span.type already set → webTags resolved immediately
492+
currentStore = { span: webSpan }
493+
enterCh.publish()
494+
const ctx0 = localPprof.time.setContext.getCall(0).args[0]
495+
assert.strictEqual(ctx0.webTags, webSpanTags)
496+
497+
// Tags update should be a no-op since webTags is already set
498+
tagsUpdateCh.publish(webSpan)
499+
assert.strictEqual(ctx0.webTags, webSpanTags)
500+
501+
profiler.stop()
502+
})
431503
})
432504
})

0 commit comments

Comments
 (0)