From ecb9c67abd3e5c5eaf0889f5f290c12d7cf7a574 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 16:10:09 -0400 Subject: [PATCH 01/31] fix(serverless): retain telemetry on Vercel --- .github/CODEOWNERS | 1 + .../datadog-plugin-http2/test/server.spec.js | 14 ++ .../src/exporters/span-stats/index.js | 4 +- packages/dd-trace/src/flush.js | 65 +++++++++ .../opentelemetry/logs/batch_log_processor.js | 18 ++- .../dd-trace/src/opentelemetry/logs/index.js | 6 + .../src/opentelemetry/logs/logger_provider.js | 11 +- .../src/opentelemetry/metrics/index.js | 6 + .../opentelemetry/metrics/meter_provider.js | 8 ++ .../metrics/otlp_http_metric_exporter.js | 6 +- .../metrics/otlp_span_stats_exporter.js | 6 +- .../metrics/periodic_metric_reader.js | 14 +- .../otlp/otlp_http_exporter_base.js | 89 ++++++++---- packages/dd-trace/src/proxy.js | 3 +- packages/dd-trace/src/serverless.js | 87 +++++++++++- packages/dd-trace/src/span_stats.js | 24 +++- packages/dd-trace/src/tracer.js | 9 ++ .../dd-trace/test/opentelemetry/logs.spec.js | 20 +++ .../test/opentelemetry/metrics.spec.js | 23 ++++ .../metrics/otlp_span_stats_exporter.spec.js | 24 ++++ packages/dd-trace/test/proxy.spec.js | 22 +++ packages/dd-trace/test/serverless.spec.js | 130 +++++++++++++++++- packages/dd-trace/test/span_stats.spec.js | 35 +++++ packages/dd-trace/test/tracer.spec.js | 21 +++ 24 files changed, 596 insertions(+), 50 deletions(-) create mode 100644 packages/dd-trace/src/flush.js diff --git a/.github/CODEOWNERS b/.github/CODEOWNERS index 57d11c1620b..58c27241862 100644 --- a/.github/CODEOWNERS +++ b/.github/CODEOWNERS @@ -61,6 +61,7 @@ /packages/dd-trace/src/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/src/azure_metadata.js @DataDog/apm-serverless /packages/dd-trace/src/serverless.js @DataDog/apm-serverless +/packages/dd-trace/src/flush.js @DataDog/apm-serverless @DataDog/apm-sdk-capabilities-js /packages/dd-trace/test/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/test/azure_metadata.spec.js @DataDog/apm-serverless /packages/dd-trace/test/serverless.spec.js @DataDog/apm-serverless diff --git a/packages/datadog-plugin-http2/test/server.spec.js b/packages/datadog-plugin-http2/test/server.spec.js index ee4c52be7da..3358c024735 100644 --- a/packages/datadog-plugin-http2/test/server.spec.js +++ b/packages/datadog-plugin-http2/test/server.spec.js @@ -9,6 +9,7 @@ const { setImmediate } = require('node:timers/promises') const { afterEach, beforeEach, describe, it } = require('mocha') const sinon = require('sinon') +const { channel } = require('dc-polyfill') const agent = require('../../dd-trace/test/plugins/agent') const web = require('../../dd-trace/src/plugins/util/web') @@ -309,6 +310,19 @@ describe('Plugin', () => { rawExpectedSchema.server ) + it('publishes a close response event', async () => { + const emit = sinon.spy() + const emitChannel = channel('apm:http2:server:response:emit') + emitChannel.subscribe(emit) + + try { + await request(http2, `http://localhost:${port}/user`) + sinon.assert.calledWithMatch(emit, { eventName: 'close' }) + } finally { + emitChannel.unsubscribe(emit) + } + }) + it('should do automatic instrumentation', done => { agent .assertFirstTraceSpan({ diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 9fa10de4f8a..eddfc42bf5f 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -8,9 +8,9 @@ class SpanStatsExporter { this._writer = new Writer({ url: this._url }) } - export (payload) { + export (payload, done) { this._writer.append(payload) - this._writer.flush() + this._writer.flush(done) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js new file mode 100644 index 00000000000..9cc5ef73f15 --- /dev/null +++ b/packages/dd-trace/src/flush.js @@ -0,0 +1,65 @@ +'use strict' + +/** + * @typedef {(done: () => void) => void | Promise} TelemetryFlusher + */ + +/** @type {Set} */ +const telemetryFlushers = new Set() + +/** + * Registers a configured telemetry pipeline for lifecycle flushing. + * @param {TelemetryFlusher} flusher + * @returns {() => void} Removes the telemetry flusher. + */ +function registerTelemetryFlusher (flusher) { + telemetryFlushers.add(flusher) + return () => telemetryFlushers.delete(flusher) +} + +/** + * Flushes the trace exporter and every registered telemetry pipeline. + * @param {{ + * _exporter?: { flush?: TelemetryFlusher }, + * _processor?: { _stats?: { forceFlush?: TelemetryFlusher } } + * }|undefined} tracer + * @param {() => void} [done] + */ +function flushAll (tracer, done) { + const traceExporter = tracer?._exporter + const traceFlusher = traceExporter?.flush + const spanStatsFlusher = tracer?._processor?._stats?.forceFlush + let pending = telemetryFlushers.size + + (typeof traceFlusher === 'function' ? 1 : 0) + + (typeof spanStatsFlusher === 'function' ? 1 : 0) + if (pending === 0) return done?.() + + const complete = () => { + if (--pending === 0) done?.() + } + + const flush = flusher => { + let flushed = false + const onFlushed = () => { + if (flushed) return + flushed = true + complete() + } + try { + const result = flusher(onFlushed) + result?.then(onFlushed, onFlushed) + } catch { + onFlushed() + } + } + + if (typeof traceFlusher === 'function') { + flush(done => traceFlusher.call(traceExporter, done)) + } + if (typeof spanStatsFlusher === 'function') { + flush(done => spanStatsFlusher.call(tracer._processor._stats, done)) + } + for (const flusher of telemetryFlushers) flush(flusher) +} + +module.exports = { flushAll, registerTelemetryFlusher } diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 46e8ba6c16a..9dc1b60773f 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -54,10 +54,21 @@ class BatchLogRecordProcessor { /** * Forces an immediate flush of all pending log records. - * @returns {undefined} Promise that resolves when flush is complete + * @param {Function} [done] Called after all pending log exports complete */ - forceFlush () { - this.#export() + forceFlush (done) { + this.#clearTimer() + const flushNext = () => { + if (this.#logRecords.length === 0) { + if (typeof this.exporter.flush === 'function') this.exporter.flush(done) + else done?.() + return + } + + const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) + this.exporter.export(logRecords, flushNext) + } + flushNext() } /** @@ -79,6 +90,7 @@ class BatchLogRecordProcessor { * @private */ #export () { + if (this.#logRecords.length === 0) return const logRecords = this.#logRecords.slice(0, this.#maxExportBatchSize) this.#logRecords = this.#logRecords.slice(this.#maxExportBatchSize) diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index d6a40ad0122..c98773e39ab 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -27,10 +27,13 @@ const os = require('os') * @package */ +const { registerTelemetryFlusher } = require('../../flush') const LoggerProvider = require('./logger_provider') const BatchLogRecordProcessor = require('./batch_log_processor') const OtlpHttpLogExporter = require('./otlp_http_log_exporter') +let unregisterTelemetryFlusher + /** * Initializes OpenTelemetry Logs support * @param {import('../../config/config-base')} config - Tracer configuration instance @@ -79,6 +82,9 @@ function initializeOpenTelemetryLogs (config) { // Register the logger provider globally with OpenTelemetry API loggerProvider.register() + // Retain only the current global provider when the tracer reinitializes. + unregisterTelemetryFlusher?.() + unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } module.exports = { diff --git a/packages/dd-trace/src/opentelemetry/logs/logger_provider.js b/packages/dd-trace/src/opentelemetry/logs/logger_provider.js index 820d3da574f..81a2cf340a4 100644 --- a/packages/dd-trace/src/opentelemetry/logs/logger_provider.js +++ b/packages/dd-trace/src/opentelemetry/logs/logger_provider.js @@ -84,12 +84,15 @@ class LoggerProvider { /** * Forces a flush of all pending log records. - * @returns {undefined} Promise that resolves when flush is n ssue cncomplete + * @param {Function} [done] Called after all pending log exports complete */ - forceFlush () { - if (!this.isShutdown) { - return this.processor?.forceFlush() + forceFlush (done) { + if (this.isShutdown || !this.processor) { + done?.() + return } + + this.processor.forceFlush(done) } /** diff --git a/packages/dd-trace/src/opentelemetry/metrics/index.js b/packages/dd-trace/src/opentelemetry/metrics/index.js index e9e16910bc7..13dfa4bf718 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/index.js +++ b/packages/dd-trace/src/opentelemetry/metrics/index.js @@ -6,10 +6,13 @@ const { metrics } = require('@opentelemetry/api') const { VERSION } = require('../../../../../version') const processTags = require('../../process-tags') +const { registerTelemetryFlusher } = require('../../flush') const MeterProvider = require('./meter_provider') const PeriodicMetricReader = require('./periodic_metric_reader') const OtlpHttpMetricExporter = require('./otlp_http_metric_exporter') +let unregisterTelemetryFlusher + /** * @typedef {import('../../config')} Config */ @@ -76,6 +79,9 @@ function initializeOpenTelemetryMetrics (config) { const meterProvider = new MeterProvider({ reader }) metrics.setGlobalMeterProvider(meterProvider) + // Retain only the current global provider when the tracer reinitializes. + unregisterTelemetryFlusher?.() + unregisterTelemetryFlusher = registerTelemetryFlusher(done => meterProvider.forceFlush(done)) } function buildResourceAttributes (tags, { reportHostname, otelSemanticsEnabled, service, env, serviceVersion } = {}) { diff --git a/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js b/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js index ebc9eeb1910..53cfcb20a57 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js +++ b/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js @@ -49,6 +49,14 @@ class MeterProvider { } return meter } + + /** + * @param {Function} [done] Called after the metric export completes + */ + forceFlush (done) { + if (this.reader) this.reader.forceFlush(done) + else done?.() + } } module.exports = MeterProvider diff --git a/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js b/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js index 8af42b70854..3bd2b305d03 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js +++ b/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js @@ -34,10 +34,11 @@ class OtlpHttpMetricExporter extends OtlpHttpExporterBase { * * @param {Map} metrics - Map of metric data to export * - * @returns {void} + * @param {Function} [done] Called after the HTTP export completes */ - export (metrics) { + export (metrics, done) { if (metrics.size === 0) { + done?.({ code: 0 }) return } @@ -56,6 +57,7 @@ class OtlpHttpMetricExporter extends OtlpHttpExporterBase { if (result.code === 0) { this.recordTelemetry('otel.metrics_export_successes', 1, additionalTags) } + done?.(result) }) } } diff --git a/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js b/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js index 018493dbf5c..337f6483392 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js +++ b/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js @@ -25,14 +25,16 @@ class OtlpStatsExporter extends OtlpHttpExporterBase { /** * @param {Array<{timeNs: number, bucket: import('../../span_stats').SpanBuckets}>} drained * @param {number} bucketSizeNs + * @param {Function} [done] Called after the HTTP export completes */ - export (drained, bucketSizeNs) { - if (drained.length === 0) return + export (drained, bucketSizeNs, done) { + if (drained.length === 0) return done?.() const payload = this.#transformer.transform(drained, bucketSizeNs) this.sendPayload(payload, (result) => { if (result.code !== 0) { log.error('Failed to export span stats: %s', result.error?.message) } + done?.() }) } } diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index a97b5cb6c99..e3ede3d0744 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -197,14 +197,18 @@ class PeriodicMetricReader { /** * Forces an immediate collection and export of all metrics. - * @returns {void} + * @param {Function} [done] Called after the metric export completes */ - forceFlush () { + forceFlush (done) { if (this.#isShutdown) { log.warn('PeriodicMetricReader is shutdown. %d measurement(s) were dropped', this.#droppedCount) + done?.() return } - this.#collectAndExport() + this.#collectAndExport(() => { + if (typeof this.exporter.flush === 'function') this.exporter.flush(done) + else done?.() + }) } /** @@ -250,7 +254,7 @@ class PeriodicMetricReader { * * @param {Function} [callback] - Called after export completes */ - #collectAndExport (callback = () => {}) { + #collectAndExport (callback) { // Atomically drain measurements for export. New measurements can be recorded // during export without interfering with this batch. const allMeasurements = this.#measurements @@ -292,7 +296,7 @@ class PeriodicMetricReader { } if (allMeasurements.length === 0) { - callback() + callback?.() return } diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index fe27cb643dd..696307680bc 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -20,6 +20,8 @@ const legacyStorage = storage('legacy') */ class OtlpHttpExporterBase { #transport = https + #activeRequests = 0 + #flushCallbacks = [] /** * Creates a new OtlpHttpExporterBase instance. @@ -88,39 +90,76 @@ class OtlpHttpExporterBase { }, } - legacyStorage.run({ noop: true }, () => { - const req = this.#transport.request(options, (res) => { - let data = '' + this.#activeRequests++ + let completed = false + const complete = result => { + if (completed) return + completed = true + this.#activeRequests-- + resultCallback(result) + if (this.#activeRequests === 0) this.#completeFlush() + } - res.on('data', (chunk) => { - data += chunk + try { + legacyStorage.run({ noop: true }, () => { + const req = this.#transport.request(options, (res) => { + let data = '' + + res.on('data', (chunk) => { + data += chunk + }) + + res.once('error', (error) => { + complete({ code: 1, error }) + }) + + res.once('end', () => { + // @ts-expect-error - res.statusCode can be undefined + if (res.statusCode >= 200 && res.statusCode < 300) { + complete({ code: 0 }) + } else { + const error = new Error(`HTTP ${res.statusCode}: ${data}`) + complete({ code: 1, error }) + } + }) }) - res.once('end', () => { - // @ts-expect-error - res.statusCode can be undefined - if (res.statusCode >= 200 && res.statusCode < 300) { - resultCallback({ code: 0 }) - } else { - const error = new Error(`HTTP ${res.statusCode}: ${data}`) - resultCallback({ code: 1, error }) - } + req.on('error', (error) => { + log.error('Error sending OTLP %s:', this.signalType, error) + complete({ code: 1, error }) }) - }) - req.on('error', (error) => { - log.error('Error sending OTLP %s:', this.signalType, error) - resultCallback({ code: 1, error }) - }) + req.once('timeout', () => { + req.destroy() + const error = new Error('Request timeout') + complete({ code: 1, error }) + }) - req.once('timeout', () => { - req.destroy() - const error = new Error('Request timeout') - resultCallback({ code: 1, error }) + req.write(payload) + req.end() }) + } catch (error) { + complete({ code: 1, error }) + } + } + + /** + * Calls back once all started OTLP requests have completed. + * @param {Function} [done] + */ + flush (done) { + if (!done) return + if (this.#activeRequests === 0) { + done() + return + } + this.#flushCallbacks.push(done) + } - req.write(payload) - req.end() - }) + #completeFlush () { + const callbacks = this.#flushCallbacks + this.#flushCallbacks = [] + for (const callback of callbacks) callback() } /** diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 3330061d831..30cb399c6bf 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -12,7 +12,7 @@ const telemetry = require('./telemetry') const nomenclature = require('./service-naming') const PluginManager = require('./plugin_manager') const NoopDogStatsDClient = require('./noop/dogstatsd') -const { IS_SERVERLESS } = require('./serverless') +const { IS_SERVERLESS, initializeServerlessTelemetry } = require('./serverless') const processTags = require('./process-tags') const { isTrue } = require('./util') const { @@ -389,6 +389,7 @@ class Tracer extends NoopProxy { if (this._tracingInitialized) { this._tracer.configure(config) this._pluginManager.configure(config) + initializeServerlessTelemetry(this._tracer) DynamicInstrumentation.configure(config) setStartupLogPluginManager(this._pluginManager) startupLog() diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 23e424b4baa..91e08e98826 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -1,7 +1,12 @@ 'use strict' +const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') +const nextRequestFinishChannel = channel('apm:next:request:finish') +const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const vercelRetentionHandlers = new WeakMap() + function getIsGCPFunction () { const isDeprecatedGCPFunction = getEnvironmentVariable('FUNCTION_NAME') !== undefined && @@ -45,14 +50,89 @@ function isInServerlessEnvironment () { /** * Gets tags describing the serverless platform where the tracer is running. * + * @param {{ isVercel: boolean }} [platform] Detected serverless platform. * @returns {string[]|undefined} */ -function getServerlessPlatformTags () { - if (getEnvironmentVariable('VERCEL') === '1') { +function getServerlessPlatformTags (platform = getServerlessPlatform()) { + if (platform.isVercel) { return getVercelPlatformTags() } } +/** + * Detects the serverless platform once while configuration is built. + * @returns {{ isVercel: boolean }} + */ +function getServerlessPlatform () { + return { isVercel: getEnvironmentVariable('VERCEL') === '1' } +} + +/** + * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + */ + +/** + * @param {TelemetryFlusher} tracer + * @param {() => void} done + * @returns {void} + */ +function flushVercelTelemetry (tracer, done) { + setImmediate(() => { + try { + tracer.flushAll(done) + } catch { + done() + } + }) +} + +function registerVercelRequestFlush (tracer) { + const waitUntil = getVercelRequestContext()?.waitUntil + if (typeof waitUntil !== 'function') return + + // Retain the invocation synchronously, then flush after Next finishes its root span. + let done + const pending = new Promise(resolve => { done = resolve }) + try { + waitUntil(pending) + flushVercelTelemetry(tracer, done) + } catch { + done() + } +} + +function getVercelRequestContext () { + return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() +} + +/** + * @param {TelemetryFlusher} tracer + * @returns {(() => void)|undefined} + */ +function registerVercelTelemetryRetention (tracer) { + const existing = vercelRetentionHandlers.get(tracer) + if (existing) return existing + + if (typeof tracer?.flushAll !== 'function') return + const flushRequest = () => registerVercelRequestFlush(tracer) + nextRequestFinishChannel.subscribe(flushRequest) + + const unregister = () => { + nextRequestFinishChannel.unsubscribe(flushRequest) + vercelRetentionHandlers.delete(tracer) + } + vercelRetentionHandlers.set(tracer, unregister) + return unregister +} + +/** + * Registers the lifecycle adapter selected by the detected serverless platform. + * @param {TelemetryFlusher} tracer + */ +function initializeServerlessTelemetry (tracer) { + if (getServerlessPlatform().isVercel) registerVercelTelemetryRetention(tracer) +} + /** * @returns {string[]|undefined} */ @@ -80,9 +160,12 @@ function getVercelPlatformTags () { module.exports = { getServerlessPlatformTags, + getServerlessPlatform, getIsGCPFunction, getIsAzureFunction, enableGCPPubSubPushSubscription, getIsFlexConsumptionAzureFunction, + registerVercelTelemetryRetention, + initializeServerlessTelemetry, IS_SERVERLESS: isInServerlessEnvironment(), } diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index 82d9d5e96ef..87f491276a8 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -208,6 +208,18 @@ class SpanStatsProcessor { } onInterval () { + this.#flush() + } + + /** + * Drains pending span statistics and waits for their export. + * @param {Function} [done] + */ + forceFlush (done) { + this.#flush(done) + } + + #flush (done) { const drained = this.#drainBuckets() if (this.enabled && !this.otlpExporter) { @@ -221,10 +233,16 @@ class SpanStatsProcessor { RuntimeID: this.tags['runtime-id'], Sequence: ++this.sequence, ProcessTags: processTags.serialized, - }) + }, done) } else if (this.otlpExporter && drained.length > 0) { - this.otlpExporter.export(drained, this.bucketSizeNs) - } + this.otlpExporter.export(drained, this.bucketSizeNs, () => { + if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) + else done?.() + }) + } else if (this.otlpExporter) { + if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) + else done?.() + } else done?.() } onSpanFinished (span) { diff --git a/packages/dd-trace/src/tracer.js b/packages/dd-trace/src/tracer.js index 8aae2b44170..5f714acd9de 100644 --- a/packages/dd-trace/src/tracer.js +++ b/packages/dd-trace/src/tracer.js @@ -13,6 +13,7 @@ const { isError } = require('./util') const { setStartupLogConfig } = require('./startup-log') const { DataStreamsCheckpointer, DataStreamsManager, DataStreamsProcessor } = require('./datastreams') const { IS_SERVERLESS } = require('./serverless') +const { flushAll } = require('./flush') const log = require('./log') // Always-on writer (console.warn), not the channel-gated `log`: these surface regardless of // DD_TRACE_DEBUG. @@ -143,6 +144,14 @@ class DatadogTracer extends Tracer { this._dataStreamsProcessor.setUrl(url) } + /** + * Flushes every configured telemetry pipeline. + * @param {Function} [done] Called after every configured export completes + */ + flushAll (done) { + flushAll(this, done) + } + scope () { return this._scope } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index 3928372c6c9..f79e25865ae 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -15,6 +15,7 @@ require('../setup/core') const { protoLogsService } = require('../../src/opentelemetry/otlp/protobuf_loader').getProtobufTypes() const { getConfigFresh } = require('../helpers/config') const { assertObjectContains } = require('../../../../integration-tests/helpers') +const BatchLogRecordProcessor = require('../../src/opentelemetry/logs/batch_log_processor') /** * @param {object} type protobufjs Type instance for the OTLP service message @@ -142,6 +143,25 @@ describe('OpenTelemetry Logs', () => { }) describe('Logs Export', () => { + it('waits for an in-flight export during forceFlush', () => { + let exportDone + let flushDone + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { exportDone = done }, + flush: (done) => { flushDone = done }, + }, 60_000, 1) + const done = sinon.spy() + + processor.onEmit({ body: 'in flight' }, { name: 'test' }) + processor.forceFlush(done) + + sinon.assert.notCalled(done) + exportDone({ code: 0 }) + sinon.assert.notCalled(done) + flushDone() + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] diff --git a/packages/dd-trace/test/opentelemetry/metrics.spec.js b/packages/dd-trace/test/opentelemetry/metrics.spec.js index 0ad70fbdc51..3d55684b41c 100644 --- a/packages/dd-trace/test/opentelemetry/metrics.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics.spec.js @@ -13,6 +13,8 @@ require('../setup/core') const { protoMetricsService } = require('../../src/opentelemetry/otlp/protobuf_loader').getProtobufTypes() const { getConfigFresh } = require('../helpers/config') const { DEFAULT_MAX_MEASUREMENT_QUEUE_SIZE } = require('../../src/opentelemetry/metrics/constants') +const MeterProvider = require('../../src/opentelemetry/metrics/meter_provider') +const PeriodicMetricReader = require('../../src/opentelemetry/metrics/periodic_metric_reader') /** * @param {object} type protobufjs Type instance for the OTLP service message @@ -661,6 +663,27 @@ describe('OpenTelemetry Meter Provider', () => { }) describe('Lifecycle', () => { + it('waits for an in-flight export during forceFlush', () => { + let exportDone + let flushDone + const reader = new PeriodicMetricReader({ + export: (metrics, done) => { exportDone = done }, + flush: (done) => { flushDone = done }, + }, 60_000, 'DELTA', 1024) + const meter = new MeterProvider({ reader }).getMeter('test') + const done = sinon.spy() + + meter.createCounter('in-flight').add(1) + reader.forceFlush(done) + + sinon.assert.notCalled(done) + exportDone({ code: 0 }) + sinon.assert.notCalled(done) + flushDone() + sinon.assert.calledOnce(done) + reader.shutdown() + }) + it('handles shutdown gracefully', async () => { setupMetrics() const provider = metrics.getMeterProvider() diff --git a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js index c1fae321295..c938903b385 100644 --- a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js @@ -179,4 +179,28 @@ describe('OtlpStatsExporter', () => { exporter.export(drained, BUCKET_SIZE_NS) assert.ok(httpStub.calledOnce) }) + + it('flushes after an in-flight HTTP export completes', () => { + let onEnd + httpStub.callsFake((options, callback) => { + const mockRes = { + statusCode: 200, + on: sinon.stub(), + once: (event, handler) => { + if (event === 'end') onEnd = handler + return mockRes + }, + } + callback(mockRes) + return mockReq + }) + const flushed = sinon.spy() + + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + exporter.flush(flushed) + + sinon.assert.notCalled(flushed) + onEnd() + sinon.assert.calledOnce(flushed) + }) }) diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index bd24e4454c0..b48cb7d06cb 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -269,6 +269,28 @@ describe('TracerProxy', () => { './flare': flare, './openfeature': openfeature, './openfeature/flagging_provider': OpenFeatureProvider, + './serverless': { + IS_SERVERLESS: false, + }, + }) + + const { enable: openfeatureRcEnable } = require('../src/openfeature/remote_config') + const noopOpenfeature = {} + + featureRegistry.registerFeature({ + name: 'openfeature', + noop: noopOpenfeature, + factory: () => openfeature, + provider: () => OpenFeatureProvider, + /** @param {object} config */ + isEnabled (config) { + return config.featureFlags.DD_FEATURE_FLAGS_ENABLED + }, + remoteConfig (rc, config, proxy) { + const subscribe = config.featureFlags.DD_FEATURE_FLAGS_ENABLED && + config.featureFlags.DD_FEATURE_FLAGS_CONFIGURATION_SOURCE === 'remote_config' + openfeatureRcEnable(rc, () => proxy.openfeature, subscribe) + }, }) proxy = new ProxyClass() diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index d33923f932b..a3c52edc412 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -1,13 +1,27 @@ 'use strict' const assert = require('node:assert/strict') +const http = require('node:http') const { describe, it, afterEach } = require('mocha') +const { logs } = require('@opentelemetry/api-logs') +const { metrics } = require('@opentelemetry/api') +const { channel } = require('dc-polyfill') require('./setup/core') -const { getServerlessPlatformTags, enableGCPPubSubPushSubscription } = require('../src/serverless') +const { + getServerlessPlatformTags, + getServerlessPlatform, + enableGCPPubSubPushSubscription, + registerVercelTelemetryRetention, + initializeServerlessTelemetry, +} = require('../src/serverless') +const Tracer = require('../src/tracer') +const { initializeOpenTelemetryLogs } = require('../src/opentelemetry/logs') +const { initializeOpenTelemetryMetrics } = require('../src/opentelemetry/metrics') const agent = require('./plugins/agent') +const { getConfigFresh } = require('./helpers/config') describe('enableGCPPubSubPushSubscription', () => { const originalKService = process.env.K_SERVICE @@ -121,4 +135,118 @@ describe('Vercel span metadata', () => { 'vercel.environment', 'preview', ]) }) + + it('records the Vercel environment in configuration', () => { + process.env = { ...environment, VERCEL: '1' } + + assert.strictEqual(getServerlessPlatform().isVercel, true) + }) +}) + +describe('Vercel telemetry retention', () => { + const requestContext = Symbol.for('@vercel/request-context') + const originalContext = globalThis[requestContext] + const endpointVariables = [ + 'VERCEL', + 'OTEL_TRACES_EXPORTER', + 'DD_LOGS_OTEL_ENABLED', + 'DD_METRICS_OTEL_ENABLED', + 'OTEL_EXPORTER_OTLP_TRACES_ENDPOINT', + 'OTEL_EXPORTER_OTLP_LOGS_ENDPOINT', + 'OTEL_EXPORTER_OTLP_METRICS_ENDPOINT', + ] + const originalEndpoints = Object.fromEntries(endpointVariables.map(name => [name, process.env[name]])) + + afterEach(() => { + if (originalContext === undefined) delete globalThis[requestContext] + else globalThis[requestContext] = originalContext + for (const name of endpointVariables) { + if (originalEndpoints[name] === undefined) delete process.env[name] + else process.env[name] = originalEndpoints[name] + } + logs.disable() + metrics.disable() + }) + + it('retains trace, log, and metric payloads until their intake responses complete', async () => { + process.env.OTEL_TRACES_EXPORTER = 'otlp' + process.env.DD_LOGS_OTEL_ENABLED = 'true' + process.env.DD_METRICS_OTEL_ENABLED = 'true' + const received = new Set() + let intakeReceived + let metricPayloads = 0 + const intake = http.createServer((req, res) => { + req.resume() + req.once('end', () => { + if (req.url === '/v1/logs') received.add('logs') + if (req.url === '/v1/metrics') { + received.add('metrics') + metricPayloads++ + } + if (req.url === '/v1/traces') received.add('traces') + res.end() + if (received.size === 3 && metricPayloads === 2) intakeReceived() + }) + }) + await new Promise(resolve => intake.listen(0, '127.0.0.1', resolve)) + const { port } = intake.address() + const endpoint = `http://127.0.0.1:${port}` + process.env.OTEL_EXPORTER_OTLP_TRACES_ENDPOINT = `${endpoint}/v1/traces` + process.env.OTEL_EXPORTER_OTLP_LOGS_ENDPOINT = `${endpoint}/v1/logs` + process.env.OTEL_EXPORTER_OTLP_METRICS_ENDPOINT = `${endpoint}/v1/metrics` + + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + const intakeRequests = new Promise(resolve => { intakeReceived = resolve }) + + let unregister + try { + const config = getConfigFresh({ service: 'serverless-flush' }) + const tracer = new Tracer(config) + initializeOpenTelemetryLogs(config) + initializeOpenTelemetryMetrics(config) + + tracer.trace('serverless.flush', {}, () => {}) + logs.getLogger('serverless-flush').emit({ body: 'flush me' }) + metrics.getMeter('serverless-flush').createCounter('flush.me').add(1) + + unregister = registerVercelTelemetryRetention(tracer) + channel('apm:next:request:finish').publish({}) + await Promise.race([ + intakeRequests, + new Promise((_resolve, reject) => setTimeout(() => reject(new Error('Missing intake signals')), 1000)), + ]) + await retained + assert.deepStrictEqual(received, new Set(['traces', 'logs', 'metrics'])) + assert.strictEqual(metricPayloads, 2) + } finally { + unregister?.() + metrics.getMeterProvider()?.reader?.shutdown() + logs.getLoggerProvider()?.shutdown?.() + await new Promise(resolve => intake.close(resolve)) + } + }) + + it('defers flushing until after Next request finish subscribers return', async () => { + process.env.VERCEL = '1' + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + const finishChannel = channel('apm:next:request:finish') + let finished = false + const tracer = { + flushAll (done) { + assert.ok(finished) + done() + }, + } + + initializeServerlessTelemetry(tracer) + finishChannel.publish({}) + finished = true + await retained + }) }) diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index 515d5e564fc..aacd578f1fe 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -87,6 +87,7 @@ const SpanStatsExporter = sinon.stub().returns(exporter) const otlpExporter = { export: sinon.stub(), + flush: sinon.stub(), } const { @@ -571,6 +572,40 @@ describe('SpanStatsProcessor', () => { assert.ok(otlpExporter.export.calledOnce) }) + it('force flushes pending OTLP span statistics', () => { + const exporter = { + export: sinon.stub().callsFake((_drained, _bucketSizeNs, done) => done()), + flush: sinon.stub().callsFake(done => done()), + } + const p = new SpanStatsProcessor(config, exporter) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) + assert.ok(flushed) + assert.strictEqual(p.buckets.size, 0) + }) + + it('force flushes pending agent span statistics', () => { + exporter.export.resetHistory() + exporter.export.callsFake((_payload, done) => done()) + const p = new SpanStatsProcessor(config) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(flushed) + assert.strictEqual(p.buckets.size, 0) + exporter.export.resetBehavior() + }) + it('should record spans when only OTLP is enabled', () => { otlpExporter.export.resetHistory() const p = new SpanStatsProcessor({ diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index ee9c4d5ec05..d108e3dcf05 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -50,6 +50,27 @@ describe('Tracer', () => { }) }) + describe('flushAll', () => { + it('flushes registered telemetry pipelines with the configured trace exporter', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + const tracer = { + _exporter: { + flush: sinon.stub().callsFake(done => done()), + }, + } + const telemetryFlusher = sinon.stub().callsFake(done => done()) + const unregister = registerTelemetryFlusher(telemetryFlusher) + let completed = false + + flushAll(tracer, () => { completed = true }) + + sinon.assert.calledOnce(tracer._exporter.flush) + sinon.assert.calledOnce(telemetryFlusher) + assert.strictEqual(completed, true) + unregister() + }) + }) + describe('trace', () => { it('should run the callback with a new span', () => { tracer.trace('name', {}, span => { From 3071c5df1413f3e2f99494e3801bce38048d261e Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 21:45:55 -0400 Subject: [PATCH 02/31] fix(serverless): retain active telemetry exports --- .../dd-trace/src/exporters/agent/index.js | 25 +++++++- packages/dd-trace/src/flush.js | 11 ++-- .../opentelemetry/logs/batch_log_processor.js | 1 + .../metrics/periodic_metric_reader.js | 1 + .../otlp/otlp_http_exporter_base.js | 27 ++++---- packages/dd-trace/src/serverless.js | 26 ++++++-- .../test/exporters/agent/exporter.spec.js | 17 +++++ .../metrics/otlp_span_stats_exporter.spec.js | 26 ++++++++ packages/dd-trace/test/serverless.spec.js | 64 +++++++++++++++++-- 9 files changed, 169 insertions(+), 29 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index e951048ab5b..b69706fc12e 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -6,6 +6,7 @@ const Writer = require('./writer') class AgentExporter { #timer + #activeFlushes = new Set() constructor (config, prioritySampler) { this._config = config @@ -44,10 +45,10 @@ class AgentExporter { const { flushInterval } = this._config if (flushInterval === 0) { - this._writer.flush() + this.#flush() } else if (this.#timer === undefined) { this.#timer = setTimeout(() => { - this._writer.flush() + this.#flush() this.#timer = undefined }, flushInterval) this.#timer.unref?.() @@ -57,7 +58,25 @@ class AgentExporter { flush (done = () => {}) { clearTimeout(this.#timer) this.#timer = undefined - this._writer.flush(done) + this.#flush() + + const activeFlushes = [...this.#activeFlushes] + if (activeFlushes.length === 0) return done() + + let pending = activeFlushes.length + const complete = () => { + if (--pending === 0) done() + } + for (const flush of activeFlushes) flush.callbacks.push(complete) + } + + #flush () { + const flush = { callbacks: [] } + this.#activeFlushes.add(flush) + this._writer.flush(() => { + this.#activeFlushes.delete(flush) + for (const callback of flush.callbacks) callback() + }) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 9cc5ef73f15..6fe4a10743d 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -1,5 +1,7 @@ 'use strict' +const log = require('./log') + /** * @typedef {(done: () => void) => void | Promise} TelemetryFlusher */ @@ -40,16 +42,17 @@ function flushAll (tracer, done) { const flush = flusher => { let flushed = false - const onFlushed = () => { + const onFlushed = error => { if (flushed) return flushed = true + if (error) log.error('Error flushing telemetry pipeline:', error) complete() } try { const result = flusher(onFlushed) - result?.then(onFlushed, onFlushed) - } catch { - onFlushed() + result?.then(onFlushed, error => onFlushed(error)) + } catch (error) { + onFlushed(error) } } diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 9dc1b60773f..370e7066aa8 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -60,6 +60,7 @@ class BatchLogRecordProcessor { this.#clearTimer() const flushNext = () => { if (this.#logRecords.length === 0) { + // A size-triggered batch can still be in flight after it leaves this queue. if (typeof this.exporter.flush === 'function') this.exporter.flush(done) else done?.() return diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index e3ede3d0744..fbf4cab33c9 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -255,6 +255,7 @@ class PeriodicMetricReader { * @param {Function} [callback] - Called after export completes */ #collectAndExport (callback) { + // Observable instruments must be collected even without synchronous measurements. // Atomically drain measurements for export. New measurements can be recorded // during export without interfering with this batch. const allMeasurements = this.#measurements diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index 696307680bc..7b90bff8746 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -20,8 +20,7 @@ const legacyStorage = storage('legacy') */ class OtlpHttpExporterBase { #transport = https - #activeRequests = 0 - #flushCallbacks = [] + #activeRequests = new Set() /** * Creates a new OtlpHttpExporterBase instance. @@ -90,14 +89,15 @@ class OtlpHttpExporterBase { }, } - this.#activeRequests++ + const activeRequest = { callbacks: [] } + this.#activeRequests.add(activeRequest) let completed = false const complete = result => { if (completed) return completed = true - this.#activeRequests-- + this.#activeRequests.delete(activeRequest) resultCallback(result) - if (this.#activeRequests === 0) this.#completeFlush() + for (const callback of activeRequest.callbacks) callback() } try { @@ -144,22 +144,21 @@ class OtlpHttpExporterBase { } /** - * Calls back once all started OTLP requests have completed. + * Calls back once OTLP requests active at the flush boundary have completed. * @param {Function} [done] */ flush (done) { if (!done) return - if (this.#activeRequests === 0) { + const activeRequests = [...this.#activeRequests] + if (activeRequests.length === 0) { done() return } - this.#flushCallbacks.push(done) - } - - #completeFlush () { - const callbacks = this.#flushCallbacks - this.#flushCallbacks = [] - for (const callback of callbacks) callback() + let pending = activeRequests.length + const complete = () => { + if (--pending === 0) done() + } + for (const request of activeRequests) request.callbacks.push(complete) } /** diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 91e08e98826..917e5f97f71 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -4,8 +4,11 @@ const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') const nextRequestFinishChannel = channel('apm:next:request:finish') +const httpRequestFinishChannel = channel('apm:http:server:request:finish') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const VERCEL_FLUSH_TIMEOUT = 2_000 const vercelRetentionHandlers = new WeakMap() +const retainedVercelRequests = new WeakSet() function getIsGCPFunction () { const isDeprecatedGCPFunction = @@ -77,18 +80,31 @@ function getServerlessPlatform () { * @returns {void} */ function flushVercelTelemetry (tracer, done) { + let completed = false + const complete = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done() + } + const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) + setImmediate(() => { try { - tracer.flushAll(done) + tracer.flushAll(complete) } catch { - done() + complete() } }) } function registerVercelRequestFlush (tracer) { - const waitUntil = getVercelRequestContext()?.waitUntil + const requestContext = getVercelRequestContext() + if (!requestContext || retainedVercelRequests.has(requestContext)) return + + const { waitUntil } = requestContext if (typeof waitUntil !== 'function') return + retainedVercelRequests.add(requestContext) // Retain the invocation synchronously, then flush after Next finishes its root span. let done @@ -116,9 +132,11 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) nextRequestFinishChannel.subscribe(flushRequest) + httpRequestFinishChannel.subscribe(flushRequest) const unregister = () => { nextRequestFinishChannel.unsubscribe(flushRequest) + httpRequestFinishChannel.unsubscribe(flushRequest) vercelRetentionHandlers.delete(tracer) } vercelRetentionHandlers.set(tracer, unregister) @@ -130,7 +148,7 @@ function registerVercelTelemetryRetention (tracer) { * @param {TelemetryFlusher} tracer */ function initializeServerlessTelemetry (tracer) { - if (getServerlessPlatform().isVercel) registerVercelTelemetryRetention(tracer) + if (getServerlessPlatform().isVercel) return registerVercelTelemetryRetention(tracer) } /** diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index e9b38fa44b9..1509bc7050a 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -112,6 +112,23 @@ describe('Exporter', () => { }) }) + describe('flush', () => { + it('waits for trace exports already in flight', () => { + const callbacks = [] + writer.flush = sinon.spy(done => callbacks.push(done)) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + exporter.export([span]) + exporter.flush(flushed) + + callbacks[1]() + sinon.assert.notCalled(flushed) + callbacks[0]() + sinon.assert.calledOnce(flushed) + }) + }) + describe('setUrl', () => { beforeEach(() => { exporter = new Exporter({ url }) diff --git a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js index c938903b385..2b3deb9b096 100644 --- a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js @@ -203,4 +203,30 @@ describe('OtlpStatsExporter', () => { onEnd() sinon.assert.calledOnce(flushed) }) + + it('does not wait for exports started after the flush boundary', () => { + const onEnd = [] + httpStub.callsFake((options, callback) => { + const mockRes = { + statusCode: 200, + on: sinon.stub(), + once: (event, handler) => { + if (event === 'end') onEnd.push(handler) + return mockRes + }, + } + callback(mockRes) + return mockReq + }) + const flushed = sinon.spy() + + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + exporter.flush(flushed) + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + + onEnd[0]() + sinon.assert.calledOnce(flushed) + onEnd[1]() + sinon.assert.calledOnce(flushed) + }) }) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index a3c52edc412..ea489e30954 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -244,9 +244,65 @@ describe('Vercel telemetry retention', () => { }, } - initializeServerlessTelemetry(tracer) - finishChannel.publish({}) - finished = true - await retained + const unregister = initializeServerlessTelemetry(tracer) + try { + finishChannel.publish({}) + finished = true + await retained + } finally { + unregister() + } + }) + + it('retains telemetry for an ordinary HTTP Vercel request only once', async () => { + let retained + let flushes = 0 + const context = { waitUntil: promise => { retained = promise } } + globalThis[requestContext] = { get: () => context } + + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes++ + done() + }, + }) + try { + channel('apm:http:server:request:finish').publish({}) + channel('apm:next:request:finish').publish({}) + await retained + assert.strictEqual(flushes, 1) + } finally { + unregister() + } + }) + + it('bounds Vercel retention when an exporter does not complete', async () => { + let retained + let timeout + const setTimeoutOriginal = global.setTimeout + const clearTimeoutOriginal = global.clearTimeout + global.setTimeout = (callback, duration) => { + timeout = { callback, duration } + return timeout + } + global.clearTimeout = () => {} + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + + let unregister + try { + unregister = registerVercelTelemetryRetention({ flushAll () {} }) + channel('apm:next:request:finish').publish({}) + await new Promise(resolve => setImmediate(resolve)) + + assert.strictEqual(timeout.duration, 2_000) + timeout.callback() + await retained + } finally { + unregister?.() + global.setTimeout = setTimeoutOriginal + global.clearTimeout = clearTimeoutOriginal + } }) }) From 2cd52d19e6a7fd9ea6b133a431c324d2f71d24d3 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 21:57:55 -0400 Subject: [PATCH 03/31] refactor(serverless): isolate Vercel lifecycle adapter --- .github/CODEOWNERS | 1 + packages/dd-trace/src/serverless.js | 113 +------------------ packages/dd-trace/src/serverless/vercel.js | 125 +++++++++++++++++++++ packages/dd-trace/test/serverless.spec.js | 8 +- 4 files changed, 134 insertions(+), 113 deletions(-) create mode 100644 packages/dd-trace/src/serverless/vercel.js diff --git a/.github/CODEOWNERS b/.github/CODEOWNERS index 58c27241862..3a69e4aaa0d 100644 --- a/.github/CODEOWNERS +++ b/.github/CODEOWNERS @@ -61,6 +61,7 @@ /packages/dd-trace/src/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/src/azure_metadata.js @DataDog/apm-serverless /packages/dd-trace/src/serverless.js @DataDog/apm-serverless +/packages/dd-trace/src/serverless/vercel.js @DataDog/apm-serverless /packages/dd-trace/src/flush.js @DataDog/apm-serverless @DataDog/apm-sdk-capabilities-js /packages/dd-trace/test/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/test/azure_metadata.spec.js @DataDog/apm-serverless diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 917e5f97f71..4fc0e94221a 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -1,15 +1,7 @@ 'use strict' -const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') -const nextRequestFinishChannel = channel('apm:next:request:finish') -const httpRequestFinishChannel = channel('apm:http:server:request:finish') -const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') -const VERCEL_FLUSH_TIMEOUT = 2_000 -const vercelRetentionHandlers = new WeakMap() -const retainedVercelRequests = new WeakSet() - function getIsGCPFunction () { const isDeprecatedGCPFunction = getEnvironmentVariable('FUNCTION_NAME') !== undefined && @@ -58,7 +50,7 @@ function isInServerlessEnvironment () { */ function getServerlessPlatformTags (platform = getServerlessPlatform()) { if (platform.isVercel) { - return getVercelPlatformTags() + return require('./serverless/vercel').getVercelPlatformTags() } } @@ -70,110 +62,14 @@ function getServerlessPlatform () { return { isVercel: getEnvironmentVariable('VERCEL') === '1' } } -/** - * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher - */ - -/** - * @param {TelemetryFlusher} tracer - * @param {() => void} done - * @returns {void} - */ -function flushVercelTelemetry (tracer, done) { - let completed = false - const complete = () => { - if (completed) return - completed = true - clearTimeout(timeout) - done() - } - const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) - - setImmediate(() => { - try { - tracer.flushAll(complete) - } catch { - complete() - } - }) -} - -function registerVercelRequestFlush (tracer) { - const requestContext = getVercelRequestContext() - if (!requestContext || retainedVercelRequests.has(requestContext)) return - - const { waitUntil } = requestContext - if (typeof waitUntil !== 'function') return - retainedVercelRequests.add(requestContext) - - // Retain the invocation synchronously, then flush after Next finishes its root span. - let done - const pending = new Promise(resolve => { done = resolve }) - try { - waitUntil(pending) - flushVercelTelemetry(tracer, done) - } catch { - done() - } -} - -function getVercelRequestContext () { - return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() -} - -/** - * @param {TelemetryFlusher} tracer - * @returns {(() => void)|undefined} - */ -function registerVercelTelemetryRetention (tracer) { - const existing = vercelRetentionHandlers.get(tracer) - if (existing) return existing - - if (typeof tracer?.flushAll !== 'function') return - const flushRequest = () => registerVercelRequestFlush(tracer) - nextRequestFinishChannel.subscribe(flushRequest) - httpRequestFinishChannel.subscribe(flushRequest) - - const unregister = () => { - nextRequestFinishChannel.unsubscribe(flushRequest) - httpRequestFinishChannel.unsubscribe(flushRequest) - vercelRetentionHandlers.delete(tracer) - } - vercelRetentionHandlers.set(tracer, unregister) - return unregister -} - /** * Registers the lifecycle adapter selected by the detected serverless platform. - * @param {TelemetryFlusher} tracer + * @param {{ flushAll?: (done: () => void) => void }} tracer */ function initializeServerlessTelemetry (tracer) { - if (getServerlessPlatform().isVercel) return registerVercelTelemetryRetention(tracer) -} - -/** - * @returns {string[]|undefined} - */ -function getVercelPlatformTags () { - let tags - const projectId = getEnvironmentVariable('VERCEL_PROJECT_ID') - if (projectId) { - tags = ['vercel.project_id', projectId] - } - - const environment = getEnvironmentVariable('VERCEL_ENV') - if (environment) { - tags ??= [] - tags.push('vercel.environment', environment) - } - - const region = getEnvironmentVariable('VERCEL_REGION') - if (region) { - tags ??= [] - tags.push('vercel.region', region) + if (getServerlessPlatform().isVercel) { + return require('./serverless/vercel').registerVercelTelemetryRetention(tracer) } - - return tags } module.exports = { @@ -183,7 +79,6 @@ module.exports = { getIsAzureFunction, enableGCPPubSubPushSubscription, getIsFlexConsumptionAzureFunction, - registerVercelTelemetryRetention, initializeServerlessTelemetry, IS_SERVERLESS: isInServerlessEnvironment(), } diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js new file mode 100644 index 00000000000..d0e4c20c1ab --- /dev/null +++ b/packages/dd-trace/src/serverless/vercel.js @@ -0,0 +1,125 @@ +'use strict' + +const { channel } = require('dc-polyfill') + +const { getEnvironmentVariable } = require('../config/helper') + +const nextRequestFinishChannel = channel('apm:next:request:finish') +const httpRequestFinishChannel = channel('apm:http:server:request:finish') +const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const VERCEL_FLUSH_TIMEOUT = 2_000 +const vercelRetentionHandlers = new WeakMap() +const retainedVercelRequests = new WeakMap() + +/** + * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + */ + +/** + * @param {TelemetryFlusher} tracer + * @param {() => void} done + * @returns {void} + */ +function flushVercelTelemetry (tracer, done) { + let completed = false + const complete = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done() + } + const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) + + setImmediate(() => { + try { + tracer.flushAll(complete) + } catch { + complete() + } + }) +} + +function registerVercelRequestFlush (tracer) { + const requestContext = getVercelRequestContext() + if (!requestContext) return + + const { waitUntil } = requestContext + if (typeof waitUntil !== 'function') return + let retainedTracers = retainedVercelRequests.get(requestContext) + if (!retainedTracers) { + retainedTracers = new WeakSet() + retainedVercelRequests.set(requestContext, retainedTracers) + } + if (retainedTracers.has(tracer)) return + retainedTracers.add(tracer) + + // Retain the invocation synchronously, then flush after Next finishes its root span. + let done + const pending = new Promise(resolve => { done = resolve }) + try { + waitUntil(pending) + flushVercelTelemetry(tracer, done) + } catch { + done() + } +} + +function getVercelRequestContext () { + return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() +} + +/** + * Retains a Vercel Node Function until configured telemetry exporters complete. + * + * @param {TelemetryFlusher} tracer + * @returns {(() => void)|undefined} + */ +function registerVercelTelemetryRetention (tracer) { + const existing = vercelRetentionHandlers.get(tracer) + if (existing) return existing + + if (typeof tracer?.flushAll !== 'function') return + const flushRequest = () => registerVercelRequestFlush(tracer) + nextRequestFinishChannel.subscribe(flushRequest) + httpRequestFinishChannel.subscribe(flushRequest) + + const unregister = () => { + nextRequestFinishChannel.unsubscribe(flushRequest) + httpRequestFinishChannel.unsubscribe(flushRequest) + vercelRetentionHandlers.delete(tracer) + } + vercelRetentionHandlers.set(tracer, unregister) + return unregister +} + +/** + * Gets Vercel deployment tags to attach to spans. + * + * @returns {string[]|undefined} + */ +function getVercelPlatformTags () { + let tags + const projectId = getEnvironmentVariable('VERCEL_PROJECT_ID') + if (projectId) { + tags = ['vercel.project_id', projectId] + } + + const environment = getEnvironmentVariable('VERCEL_ENV') + if (environment) { + tags ??= [] + tags.push('vercel.environment', environment) + } + + const region = getEnvironmentVariable('VERCEL_REGION') + if (region) { + tags ??= [] + tags.push('vercel.region', region) + } + + return tags +} + +module.exports = { + getVercelPlatformTags, + registerVercelTelemetryRetention, +} diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index ea489e30954..b1ce92bd061 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -14,9 +14,9 @@ const { getServerlessPlatformTags, getServerlessPlatform, enableGCPPubSubPushSubscription, - registerVercelTelemetryRetention, initializeServerlessTelemetry, } = require('../src/serverless') +const { registerVercelTelemetryRetention } = require('../src/serverless/vercel') const Tracer = require('../src/tracer') const { initializeOpenTelemetryLogs } = require('../src/opentelemetry/logs') const { initializeOpenTelemetryMetrics } = require('../src/opentelemetry/metrics') @@ -255,9 +255,9 @@ describe('Vercel telemetry retention', () => { }) it('retains telemetry for an ordinary HTTP Vercel request only once', async () => { - let retained + const retained = [] let flushes = 0 - const context = { waitUntil: promise => { retained = promise } } + const context = { waitUntil: promise => { retained.push(promise) } } globalThis[requestContext] = { get: () => context } const unregister = registerVercelTelemetryRetention({ @@ -269,7 +269,7 @@ describe('Vercel telemetry retention', () => { try { channel('apm:http:server:request:finish').publish({}) channel('apm:next:request:finish').publish({}) - await retained + await Promise.all(retained) assert.strictEqual(flushes, 1) } finally { unregister() From a8011be70b14996169f10758e3548f2935f87c4a Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 22:16:48 -0400 Subject: [PATCH 04/31] docs(otlp): clarify logger flush registration --- packages/dd-trace/src/opentelemetry/logs/index.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index c98773e39ab..7213c79aa21 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -80,9 +80,9 @@ function initializeOpenTelemetryLogs (config) { // Create logger provider with processor for Datadog Agent export const loggerProvider = new LoggerProvider({ processor }) - // Register the logger provider globally with OpenTelemetry API + // Expose this provider to application calls through the OpenTelemetry Logs API. loggerProvider.register() - // Retain only the current global provider when the tracer reinitializes. + // Remove a previous provider callback before replacing it during tracer reinitialization. unregisterTelemetryFlusher?.() unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } From c8eb4e284b2764c8913285641726f3937e44ed77 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 09:27:41 -0400 Subject: [PATCH 05/31] docs(serverless): clarify telemetry flush registry --- packages/dd-trace/src/flush.js | 6 ++++-- packages/dd-trace/src/opentelemetry/logs/index.js | 3 ++- packages/dd-trace/src/opentelemetry/metrics/index.js | 3 ++- 3 files changed, 8 insertions(+), 4 deletions(-) diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 6fe4a10743d..38e29a5dcaf 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -10,12 +10,14 @@ const log = require('./log') const telemetryFlushers = new Set() /** - * Registers a configured telemetry pipeline for lifecycle flushing. + * Registers a configured telemetry pipeline so serverless lifecycle retention + * waits for its final export alongside trace delivery. * @param {TelemetryFlusher} flusher - * @returns {() => void} Removes the telemetry flusher. + * @returns {() => void} Removes this pipeline when its provider is replaced. */ function registerTelemetryFlusher (flusher) { telemetryFlushers.add(flusher) + // Avoid retaining a replaced provider or flushing it alongside the new one. return () => telemetryFlushers.delete(flusher) } diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index 7213c79aa21..03606c94af9 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -82,8 +82,9 @@ function initializeOpenTelemetryLogs (config) { // Expose this provider to application calls through the OpenTelemetry Logs API. loggerProvider.register() - // Remove a previous provider callback before replacing it during tracer reinitialization. + // Remove the old provider callback so lifecycle retention flushes only this global provider. unregisterTelemetryFlusher?.() + // Include final log batches in lifecycle retention with trace delivery. unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } diff --git a/packages/dd-trace/src/opentelemetry/metrics/index.js b/packages/dd-trace/src/opentelemetry/metrics/index.js index 13dfa4bf718..f457a341ea5 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/index.js +++ b/packages/dd-trace/src/opentelemetry/metrics/index.js @@ -79,8 +79,9 @@ function initializeOpenTelemetryMetrics (config) { const meterProvider = new MeterProvider({ reader }) metrics.setGlobalMeterProvider(meterProvider) - // Retain only the current global provider when the tracer reinitializes. + // Remove the old provider callback so lifecycle retention flushes only this global provider. unregisterTelemetryFlusher?.() + // Include the final metric collection and export in lifecycle retention. unregisterTelemetryFlusher = registerTelemetryFlusher(done => meterProvider.forceFlush(done)) } From f077780cb1735e298f503dbcaea96acf5856963d Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 09:31:13 -0400 Subject: [PATCH 06/31] test(otlp): cover multi-batch log flushing --- .../opentelemetry/logs/batch_log_processor.js | 5 ++- .../dd-trace/test/opentelemetry/logs.spec.js | 41 +++++++++++++++++++ 2 files changed, 45 insertions(+), 1 deletion(-) diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 370e7066aa8..4287ffc69cf 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -60,12 +60,15 @@ class BatchLogRecordProcessor { this.#clearTimer() const flushNext = () => { if (this.#logRecords.length === 0) { - // A size-triggered batch can still be in flight after it leaves this queue. + // The queue is empty after a size/timer batch is handed to the exporter, but + // its HTTP request can still be in flight. Join it before lifecycle completion. if (typeof this.exporter.flush === 'function') this.exporter.flush(done) else done?.() return } + // Drain queued records one batch at a time; the final exporter flush joins + // earlier size-triggered batches that are still in flight. const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) this.exporter.export(logRecords, flushNext) } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index f79e25865ae..0752d95c66f 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -162,6 +162,47 @@ describe('OpenTelemetry Logs', () => { sinon.assert.calledOnce(done) }) + it('drains queued batches and waits for earlier size-triggered exports', () => { + const batches = [] + const callbacks = [] + const flushCallbacks = [] + let activeExports = 0 + const completeFlushes = () => { + if (activeExports !== 0) return + while (flushCallbacks.length > 0) flushCallbacks.shift()() + } + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { + batches.push(records) + activeExports++ + callbacks.push(() => { + activeExports-- + done({ code: 0 }) + completeFlushes() + }) + }, + flush: (done) => { + if (activeExports === 0) done() + else flushCallbacks.push(done) + }, + }, 60_000, 2) + const done = sinon.spy() + + for (let index = 0; index < 5; index++) { + processor.onEmit({ body: index }, { name: 'test' }) + } + processor.forceFlush(done) + + assert.deepStrictEqual(batches.map(batch => batch.map(record => record.body)), [ + [0, 1], [2, 3], [4], + ]) + callbacks.shift()() + callbacks.shift()() + callbacks.shift()() + + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] From 295ba2d137655c2eab1cfa1f3e7653feec427cf8 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:02:20 -0400 Subject: [PATCH 07/31] refactor(serverless): bound flushing in tracer --- packages/dd-trace/src/flush.js | 22 +++++++++++++++--- packages/dd-trace/src/serverless/vercel.js | 15 +++---------- packages/dd-trace/src/tracer.js | 5 +++-- packages/dd-trace/test/serverless.spec.js | 26 +++++++++------------- packages/dd-trace/test/tracer.spec.js | 21 +++++++++++++++++ 5 files changed, 56 insertions(+), 33 deletions(-) diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 38e29a5dcaf..ad4482a72f3 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -28,18 +28,34 @@ function registerTelemetryFlusher (flusher) { * _processor?: { _stats?: { forceFlush?: TelemetryFlusher } } * }|undefined} tracer * @param {() => void} [done] + * @param {{ timeout?: number }} [options] */ -function flushAll (tracer, done) { +function flushAll (tracer, done, options) { const traceExporter = tracer?._exporter const traceFlusher = traceExporter?.flush const spanStatsFlusher = tracer?._processor?._stats?.forceFlush let pending = telemetryFlushers.size + (typeof traceFlusher === 'function' ? 1 : 0) + (typeof spanStatsFlusher === 'function' ? 1 : 0) - if (pending === 0) return done?.() + let completed = false + let timeout + const finish = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done?.() + } const complete = () => { - if (--pending === 0) done?.() + if (--pending === 0) finish() + } + + if (pending === 0) return finish() + if (options?.timeout) { + timeout = setTimeout(() => { + log.warn('Timed out waiting for telemetry flush after %dms', options.timeout) + finish() + }, options.timeout) } const flush = flusher => { diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index d0e4c20c1ab..7fc7e2d6854 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -12,7 +12,7 @@ const vercelRetentionHandlers = new WeakMap() const retainedVercelRequests = new WeakMap() /** - * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + * @typedef {{ flushAll?: (done: () => void, options?: { timeout?: number }) => void }} TelemetryFlusher */ /** @@ -21,20 +21,11 @@ const retainedVercelRequests = new WeakMap() * @returns {void} */ function flushVercelTelemetry (tracer, done) { - let completed = false - const complete = () => { - if (completed) return - completed = true - clearTimeout(timeout) - done() - } - const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) - setImmediate(() => { try { - tracer.flushAll(complete) + tracer.flushAll(done, { timeout: VERCEL_FLUSH_TIMEOUT }) } catch { - complete() + done() } }) } diff --git a/packages/dd-trace/src/tracer.js b/packages/dd-trace/src/tracer.js index 5f714acd9de..1c9335e9019 100644 --- a/packages/dd-trace/src/tracer.js +++ b/packages/dd-trace/src/tracer.js @@ -147,9 +147,10 @@ class DatadogTracer extends Tracer { /** * Flushes every configured telemetry pipeline. * @param {Function} [done] Called after every configured export completes + * @param {{ timeout?: number }} [options] Bounds this flush operation. */ - flushAll (done) { - flushAll(this, done) + flushAll (done, options) { + flushAll(this, done, options) } scope () { diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index b1ce92bd061..2104f3e59d4 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -276,33 +276,27 @@ describe('Vercel telemetry retention', () => { } }) - it('bounds Vercel retention when an exporter does not complete', async () => { + it('passes Vercel retention timeout to the telemetry flush barrier', async () => { let retained - let timeout - const setTimeoutOriginal = global.setTimeout - const clearTimeoutOriginal = global.clearTimeout - global.setTimeout = (callback, duration) => { - timeout = { callback, duration } - return timeout - } - global.clearTimeout = () => {} + let options globalThis[requestContext] = { get: () => ({ waitUntil: promise => { retained = promise } }), } let unregister try { - unregister = registerVercelTelemetryRetention({ flushAll () {} }) + unregister = registerVercelTelemetryRetention({ + flushAll (done, flushOptions) { + options = flushOptions + done() + }, + }) channel('apm:next:request:finish').publish({}) - await new Promise(resolve => setImmediate(resolve)) - - assert.strictEqual(timeout.duration, 2_000) - timeout.callback() await retained + + assert.deepStrictEqual(options, { timeout: 2_000 }) } finally { unregister?.() - global.setTimeout = setTimeoutOriginal - global.clearTimeout = clearTimeoutOriginal } }) }) diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index d108e3dcf05..7aaed371459 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -69,6 +69,27 @@ describe('Tracer', () => { assert.strictEqual(completed, true) unregister() }) + + it('bounds configured telemetry flushing', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + const timeout = sinon.stub(global, 'setTimeout') + const clearTimeout = sinon.stub(global, 'clearTimeout') + const done = sinon.spy() + const unregister = registerTelemetryFlusher(() => {}) + + try { + flushAll({}, done, { timeout: 2_000 }) + + sinon.assert.calledWith(timeout, sinon.match.func, 2_000) + timeout.firstCall.args[0]() + sinon.assert.calledOnce(done) + sinon.assert.called(clearTimeout) + } finally { + unregister() + timeout.restore() + clearTimeout.restore() + } + }) }) describe('trace', () => { From fa7c7dde65b965068b75439d7e803c85ca0d6e1e Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:11:37 -0400 Subject: [PATCH 08/31] fix(serverless): retain span stats and bounded log batches --- .../src/exporters/span-stats/index.js | 26 +++++++++++++++++- packages/dd-trace/src/flush.js | 1 + .../opentelemetry/logs/batch_log_processor.js | 27 ++++++++++++------- .../dd-trace/test/opentelemetry/logs.spec.js | 21 +++++++++++++++ 4 files changed, 65 insertions(+), 10 deletions(-) diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index eddfc42bf5f..7d09d8f465b 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -3,6 +3,8 @@ const { Writer } = require('./writer') class SpanStatsExporter { + #activeFlushes = new Set() + constructor (config) { this._url = config.url this._writer = new Writer({ url: this._url }) @@ -10,7 +12,29 @@ class SpanStatsExporter { export (payload, done) { this._writer.append(payload) - this._writer.flush(done) + this.#flush(done) + } + + flush (done = () => {}) { + this.#flush() + + const activeFlushes = [...this.#activeFlushes] + if (activeFlushes.length === 0) return done() + + let pending = activeFlushes.length + const complete = () => { + if (--pending === 0) done() + } + for (const flush of activeFlushes) flush.callbacks.push(complete) + } + + #flush (done) { + const flush = { callbacks: done ? [done] : [] } + this.#activeFlushes.add(flush) + this._writer.flush(() => { + this.#activeFlushes.delete(flush) + for (const callback of flush.callbacks) callback() + }) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index ad4482a72f3..ef961f8d633 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -34,6 +34,7 @@ function flushAll (tracer, done, options) { const traceExporter = tracer?._exporter const traceFlusher = traceExporter?.flush const spanStatsFlusher = tracer?._processor?._stats?.forceFlush + // TODO: Include DSM after DataStreamsProcessor exposes a completion-aware flush API. let pending = telemetryFlushers.size + (typeof traceFlusher === 'function' ? 1 : 0) + (typeof spanStatsFlusher === 'function' ? 1 : 0) diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 4287ffc69cf..67fe227988f 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -58,19 +58,28 @@ class BatchLogRecordProcessor { */ forceFlush (done) { this.#clearTimer() + // Flush only records present at this boundary. New records belong to the + // later request that produced them and must not extend this lifecycle flush. + const logRecords = this.#logRecords + this.#logRecords = [] + let pending = 2 + const complete = () => { + if (--pending === 0) done?.() + } + + // Join exports already active at this boundary before draining this snapshot. + if (typeof this.exporter.flush === 'function') this.exporter.flush(complete) + else complete() + const flushNext = () => { - if (this.#logRecords.length === 0) { - // The queue is empty after a size/timer batch is handed to the exporter, but - // its HTTP request can still be in flight. Join it before lifecycle completion. - if (typeof this.exporter.flush === 'function') this.exporter.flush(done) - else done?.() + if (logRecords.length === 0) { + complete() return } - // Drain queued records one batch at a time; the final exporter flush joins - // earlier size-triggered batches that are still in flight. - const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) - this.exporter.export(logRecords, flushNext) + // Drain the boundary snapshot one batch at a time. + const batch = logRecords.splice(0, this.#maxExportBatchSize) + this.exporter.export(batch, flushNext) } flushNext() } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index 0752d95c66f..2ec004d14b0 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -203,6 +203,27 @@ describe('OpenTelemetry Logs', () => { sinon.assert.calledOnce(done) }) + it('does not wait for records emitted after the flush boundary', () => { + const exports = [] + let firstExportDone + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { + exports.push(records.map(record => record.body)) + if (records[0].body === 'before') firstExportDone = done + }, + flush: done => done(), + }, 60_000, 2) + const done = sinon.spy() + + processor.onEmit({ body: 'before' }, { name: 'test' }) + processor.forceFlush(done) + processor.onEmit({ body: 'after' }, { name: 'test' }) + firstExportDone({ code: 0 }) + + assert.deepStrictEqual(exports, [['before']]) + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] From b4dc8475bf1e52566bd9e408ee124ce089b62269 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:11:51 -0400 Subject: [PATCH 09/31] test(span-stats): cover in-flight export flush --- .../test/exporters/span-stats/exporter.spec.js | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index 30c431d7e03..4caccdd762f 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -41,6 +41,22 @@ describe('span-stats exporter', () => { sinon.assert.called(writer.flush) }) + it('waits for an in-flight export during flush', () => { + exporter = new Exporter({ url }) + let inFlightDone + writer.flush = sinon.stub() + writer.flush.onFirstCall().callsFake(done => { inFlightDone = done }) + writer.flush.onSecondCall().callsFake(done => done()) + const done = sinon.spy() + + exporter.export('in flight') + exporter.flush(done) + + sinon.assert.notCalled(done) + inFlightDone() + sinon.assert.calledOnce(done) + }) + it('should set url from config', () => { const url = new URL('http://0.0.0.0:1234') From 49242e93fcddca257c45783653566d3115f370d0 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:19:13 -0400 Subject: [PATCH 10/31] fix(serverless): wait for Vercel response completion --- packages/dd-trace/src/serverless/vercel.js | 11 +++--- packages/dd-trace/test/serverless.spec.js | 41 ++++++++++++++++------ 2 files changed, 38 insertions(+), 14 deletions(-) diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index 7fc7e2d6854..9b50cab1998 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -4,8 +4,8 @@ const { channel } = require('dc-polyfill') const { getEnvironmentVariable } = require('../config/helper') -const nextRequestFinishChannel = channel('apm:next:request:finish') const httpRequestFinishChannel = channel('apm:http:server:request:finish') +const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') const VERCEL_FLUSH_TIMEOUT = 2_000 const vercelRetentionHandlers = new WeakMap() @@ -44,7 +44,7 @@ function registerVercelRequestFlush (tracer) { if (retainedTracers.has(tracer)) return retainedTracers.add(tracer) - // Retain the invocation synchronously, then flush after Next finishes its root span. + // Retain the invocation synchronously, then flush after the response completes. let done const pending = new Promise(resolve => { done = resolve }) try { @@ -71,12 +71,15 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) - nextRequestFinishChannel.subscribe(flushRequest) + const flushHttp2Response = ({ eventName }) => { + if (eventName === 'finish' || eventName === 'close') flushRequest() + } httpRequestFinishChannel.subscribe(flushRequest) + http2ResponseEmitChannel.subscribe(flushHttp2Response) const unregister = () => { - nextRequestFinishChannel.unsubscribe(flushRequest) httpRequestFinishChannel.unsubscribe(flushRequest) + http2ResponseEmitChannel.unsubscribe(flushHttp2Response) vercelRetentionHandlers.delete(tracer) } vercelRetentionHandlers.set(tracer, unregister) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index 2104f3e59d4..4e47e9e2899 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -213,11 +213,8 @@ describe('Vercel telemetry retention', () => { metrics.getMeter('serverless-flush').createCounter('flush.me').add(1) unregister = registerVercelTelemetryRetention(tracer) - channel('apm:next:request:finish').publish({}) - await Promise.race([ - intakeRequests, - new Promise((_resolve, reject) => setTimeout(() => reject(new Error('Missing intake signals')), 1000)), - ]) + channel('apm:http:server:request:finish').publish({}) + await intakeRequests await retained assert.deepStrictEqual(received, new Set(['traces', 'logs', 'metrics'])) assert.strictEqual(metricPayloads, 2) @@ -229,13 +226,14 @@ describe('Vercel telemetry retention', () => { } }) - it('defers flushing until after Next request finish subscribers return', async () => { + it('waits for HTTP response completion after Next request finish', async () => { process.env.VERCEL = '1' let retained globalThis[requestContext] = { get: () => ({ waitUntil: promise => { retained = promise } }), } - const finishChannel = channel('apm:next:request:finish') + const nextFinishChannel = channel('apm:next:request:finish') + const httpFinishChannel = channel('apm:http:server:request:finish') let finished = false const tracer = { flushAll (done) { @@ -246,8 +244,10 @@ describe('Vercel telemetry retention', () => { const unregister = initializeServerlessTelemetry(tracer) try { - finishChannel.publish({}) + nextFinishChannel.publish({}) + assert.strictEqual(retained, undefined) finished = true + httpFinishChannel.publish({}) await retained } finally { unregister() @@ -268,7 +268,6 @@ describe('Vercel telemetry retention', () => { }) try { channel('apm:http:server:request:finish').publish({}) - channel('apm:next:request:finish').publish({}) await Promise.all(retained) assert.strictEqual(flushes, 1) } finally { @@ -291,7 +290,7 @@ describe('Vercel telemetry retention', () => { done() }, }) - channel('apm:next:request:finish').publish({}) + channel('apm:http:server:request:finish').publish({}) await retained assert.deepStrictEqual(options, { timeout: 2_000 }) @@ -299,4 +298,26 @@ describe('Vercel telemetry retention', () => { unregister?.() } }) + + it('retains telemetry at HTTP/2 response completion', async () => { + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + + let flushes = 0 + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes++ + done() + }, + }) + try { + channel('apm:http2:server:response:emit').publish({ eventName: 'close' }) + await retained + assert.strictEqual(flushes, 1) + } finally { + unregister() + } + }) }) From 77548615b97aaf75f68457314f6c194fafe906aa Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 12:36:06 -0400 Subject: [PATCH 11/31] fix(serverless): order Vercel telemetry flushing --- .../src/exporters/span-stats/index.js | 11 ++++------- .../metrics/periodic_metric_reader.js | 13 +++++++++---- .../otlp/otlp_http_exporter_base.js | 1 + packages/dd-trace/src/serverless/vercel.js | 4 ++-- .../test/opentelemetry/metrics.spec.js | 18 ++++++++++++------ packages/dd-trace/test/proxy.spec.js | 19 ------------------- packages/dd-trace/test/serverless.spec.js | 2 ++ 7 files changed, 30 insertions(+), 38 deletions(-) diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 7d09d8f465b..51141be6db2 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -15,17 +15,14 @@ class SpanStatsExporter { this.#flush(done) } - flush (done = () => {}) { - this.#flush() - + flush (done) { const activeFlushes = [...this.#activeFlushes] - if (activeFlushes.length === 0) return done() - - let pending = activeFlushes.length + let pending = activeFlushes.length + 1 const complete = () => { - if (--pending === 0) done() + if (--pending === 0) done?.() } for (const flush of activeFlushes) flush.callbacks.push(complete) + this.#flush(complete) } #flush (done) { diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index fbf4cab33c9..32de8d9ae99 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -205,10 +205,15 @@ class PeriodicMetricReader { done?.() return } - this.#collectAndExport(() => { - if (typeof this.exporter.flush === 'function') this.exporter.flush(done) - else done?.() - }) + let pending = 2 + const complete = () => { + if (--pending === 0) done?.() + } + + // Snapshot requests already active before starting this flush's export. + if (typeof this.exporter.flush === 'function') this.exporter.flush(complete) + else complete() + this.#collectAndExport(complete) } /** diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index 7b90bff8746..d9bba361ad8 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -139,6 +139,7 @@ class OtlpHttpExporterBase { req.end() }) } catch (error) { + log.error('Error sending OTLP %s:', this.signalType, error) complete({ code: 1, error }) } } diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index 9b50cab1998..bcadd1ca127 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -7,7 +7,7 @@ const { getEnvironmentVariable } = require('../config/helper') const httpRequestFinishChannel = channel('apm:http:server:request:finish') const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') -const VERCEL_FLUSH_TIMEOUT = 2_000 +const VERCEL_FLUSH_TIMEOUT = 2000 const vercelRetentionHandlers = new WeakMap() const retainedVercelRequests = new WeakMap() @@ -72,7 +72,7 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) const flushHttp2Response = ({ eventName }) => { - if (eventName === 'finish' || eventName === 'close') flushRequest() + if (eventName === 'close') flushRequest() } httpRequestFinishChannel.subscribe(flushRequest) http2ResponseEmitChannel.subscribe(flushHttp2Response) diff --git a/packages/dd-trace/test/opentelemetry/metrics.spec.js b/packages/dd-trace/test/opentelemetry/metrics.spec.js index 3d55684b41c..4f12bba0004 100644 --- a/packages/dd-trace/test/opentelemetry/metrics.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics.spec.js @@ -664,23 +664,29 @@ describe('OpenTelemetry Meter Provider', () => { describe('Lifecycle', () => { it('waits for an in-flight export during forceFlush', () => { - let exportDone - let flushDone + const exports = [] + const flushes = [] const reader = new PeriodicMetricReader({ - export: (metrics, done) => { exportDone = done }, - flush: (done) => { flushDone = done }, + export: (metrics, done) => { exports.push(done) }, + flush: (done) => { flushes.push(done) }, }, 60_000, 'DELTA', 1024) const meter = new MeterProvider({ reader }).getMeter('test') + const firstDone = sinon.spy() const done = sinon.spy() meter.createCounter('in-flight').add(1) + reader.forceFlush(firstDone) + flushes.shift()() + meter.createCounter('boundary').add(1) reader.forceFlush(done) sinon.assert.notCalled(done) - exportDone({ code: 0 }) + assert.strictEqual(exports.length, 2) + exports[1]({ code: 0 }) sinon.assert.notCalled(done) - flushDone() + flushes[0]() sinon.assert.calledOnce(done) + exports[0]({ code: 0 }) reader.shutdown() }) diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index b48cb7d06cb..0dfc64e1e3b 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -274,25 +274,6 @@ describe('TracerProxy', () => { }, }) - const { enable: openfeatureRcEnable } = require('../src/openfeature/remote_config') - const noopOpenfeature = {} - - featureRegistry.registerFeature({ - name: 'openfeature', - noop: noopOpenfeature, - factory: () => openfeature, - provider: () => OpenFeatureProvider, - /** @param {object} config */ - isEnabled (config) { - return config.featureFlags.DD_FEATURE_FLAGS_ENABLED - }, - remoteConfig (rc, config, proxy) { - const subscribe = config.featureFlags.DD_FEATURE_FLAGS_ENABLED && - config.featureFlags.DD_FEATURE_FLAGS_CONFIGURATION_SOURCE === 'remote_config' - openfeatureRcEnable(rc, () => proxy.openfeature, subscribe) - }, - }) - proxy = new ProxyClass() }) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index 4e47e9e2899..f2f989bea91 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -313,6 +313,8 @@ describe('Vercel telemetry retention', () => { }, }) try { + channel('apm:http2:server:response:emit').publish({ eventName: 'finish' }) + assert.strictEqual(retained, undefined) channel('apm:http2:server:response:emit').publish({ eventName: 'close' }) await retained assert.strictEqual(flushes, 1) From 6d1e78ab9e1d77e218baff348206a1ce9c05ce15 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 12:50:30 -0400 Subject: [PATCH 12/31] fix(exporters): clean up failed flush records --- packages/dd-trace/src/exporters/agent/index.js | 10 ++++++++-- packages/dd-trace/src/exporters/span-stats/index.js | 10 ++++++++-- .../dd-trace/test/exporters/agent/exporter.spec.js | 13 +++++++++++++ .../test/exporters/span-stats/exporter.spec.js | 13 +++++++++++++ 4 files changed, 42 insertions(+), 4 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index b69706fc12e..744080acc93 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -73,10 +73,16 @@ class AgentExporter { #flush () { const flush = { callbacks: [] } this.#activeFlushes.add(flush) - this._writer.flush(() => { + const complete = () => { this.#activeFlushes.delete(flush) for (const callback of flush.callbacks) callback() - }) + } + try { + this._writer.flush(complete) + } catch (error) { + complete() + throw error + } } } diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 51141be6db2..ca099441ac6 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -28,10 +28,16 @@ class SpanStatsExporter { #flush (done) { const flush = { callbacks: done ? [done] : [] } this.#activeFlushes.add(flush) - this._writer.flush(() => { + const complete = () => { this.#activeFlushes.delete(flush) for (const callback of flush.callbacks) callback() - }) + } + try { + this._writer.flush(complete) + } catch (error) { + complete() + throw error + } } } diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index 1509bc7050a..40bc80d83e3 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -127,6 +127,19 @@ describe('Exporter', () => { callbacks[0]() sinon.assert.calledOnce(flushed) }) + + it('does not retain a failed writer flush', () => { + writer.flush = sinon.stub() + writer.flush.onFirstCall().throws(new Error('encode failed')) + writer.flush.onSecondCall().callsFake(done => done()) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + assert.throws(() => exporter.export([span]), /encode failed/) + exporter.flush(flushed) + + sinon.assert.calledOnce(flushed) + }) }) describe('setUrl', () => { diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index 4caccdd762f..635e4d816f8 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -57,6 +57,19 @@ describe('span-stats exporter', () => { sinon.assert.calledOnce(done) }) + it('does not retain a failed writer flush', () => { + writer.flush = sinon.stub() + writer.flush.onFirstCall().throws(new Error('encode failed')) + writer.flush.onSecondCall().callsFake(done => done()) + exporter = new Exporter({ url }) + const done = sinon.spy() + + assert.throws(() => exporter.export('failed export'), /encode failed/) + exporter.flush(done) + + sinon.assert.calledOnce(done) + }) + it('should set url from config', () => { const url = new URL('http://0.0.0.0:1234') From af345463a47eaa1f57dd86964f1808d8e90d34b3 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 11:26:50 -0400 Subject: [PATCH 13/31] fix(serverless): retain outer Vercel telemetry --- packages/dd-trace/src/serverless/vercel.js | 8 ------- packages/dd-trace/src/span_stats.js | 6 ++++- packages/dd-trace/test/serverless.spec.js | 28 ++++++++++++++++++++++ packages/dd-trace/test/span_stats.spec.js | 27 ++++++++++++++++++++- 4 files changed, 59 insertions(+), 10 deletions(-) diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index bcadd1ca127..eb65fcb0bf3 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -9,7 +9,6 @@ const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') const VERCEL_FLUSH_TIMEOUT = 2000 const vercelRetentionHandlers = new WeakMap() -const retainedVercelRequests = new WeakMap() /** * @typedef {{ flushAll?: (done: () => void, options?: { timeout?: number }) => void }} TelemetryFlusher @@ -36,13 +35,6 @@ function registerVercelRequestFlush (tracer) { const { waitUntil } = requestContext if (typeof waitUntil !== 'function') return - let retainedTracers = retainedVercelRequests.get(requestContext) - if (!retainedTracers) { - retainedTracers = new WeakSet() - retainedVercelRequests.set(requestContext, retainedTracers) - } - if (retainedTracers.has(tracer)) return - retainedTracers.add(tracer) // Retain the invocation synchronously, then flush after the response completes. let done diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index 87f491276a8..c2c4626f6cd 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -233,7 +233,11 @@ class SpanStatsProcessor { RuntimeID: this.tags['runtime-id'], Sequence: ++this.sequence, ProcessTags: processTags.serialized, - }, done) + }) + // `export` can overlap an interval export. Use the exporter's barrier so + // this lifecycle flush waits for both that existing request and this + // boundary payload before Vercel releases the invocation. + if (done) this.exporter.flush(done) } else if (this.otlpExporter && drained.length > 0) { this.otlpExporter.export(drained, this.bucketSizeNs, () => { if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index f2f989bea91..89d36b942fe 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -275,6 +275,34 @@ describe('Vercel telemetry retention', () => { } }) + it('retains telemetry again when an outer Vercel response follows a nested request', async () => { + const retained = [] + const flushes = [] + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained.push(promise) } }), + } + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes.push(done) + }, + }) + try { + channel('apm:http:server:request:finish').publish({ req: {} }) + await new Promise(resolve => setImmediate(resolve)) + channel('apm:http:server:request:finish').publish({ req: {} }) + await new Promise(resolve => setImmediate(resolve)) + + // Other tracers initialized by this file can share this request context; + // the callback count below isolates this test's tracer. + assert.ok(retained.length >= 2) + assert.strictEqual(flushes.length, 2) + flushes[0]() + flushes[1]() + } finally { + unregister() + } + }) + it('passes Vercel retention timeout to the telemetry flush barrier', async () => { let retained let options diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index aacd578f1fe..10ad34c0426 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -81,6 +81,7 @@ const syntheticSpan = { const exporter = { export: sinon.stub(), + flush: sinon.stub(), } const SpanStatsExporter = sinon.stub().returns(exporter) @@ -592,7 +593,9 @@ describe('SpanStatsProcessor', () => { it('force flushes pending agent span statistics', () => { exporter.export.resetHistory() - exporter.export.callsFake((_payload, done) => done()) + exporter.flush.resetHistory() + exporter.export.callsFake(() => {}) + exporter.flush.callsFake(done => done()) const p = new SpanStatsProcessor(config) clearTimeout(p.timer) p.onSpanFinished(topLevelSpan) @@ -601,9 +604,31 @@ describe('SpanStatsProcessor', () => { p.forceFlush(() => { flushed = true }) assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) assert.ok(flushed) assert.strictEqual(p.buckets.size, 0) exporter.export.resetBehavior() + exporter.flush.resetBehavior() + }) + + it('joins an in-flight agent span statistics export during force flush', () => { + exporter.export.resetHistory() + exporter.flush.resetHistory() + const p = new SpanStatsProcessor(config) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushDone + exporter.flush.callsFake(done => { flushDone = done }) + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) + assert.strictEqual(flushed, false) + flushDone() + assert.strictEqual(flushed, true) + exporter.flush.resetBehavior() }) it('should record spans when only OTLP is enabled', () => { From 7caaca0c086bd6e7d182c0efae4a7ba5d39d6543 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 11:46:17 -0400 Subject: [PATCH 14/31] fix(exporters): retain in-flight traces after flush failure --- packages/dd-trace/src/exporters/agent/index.js | 11 +++++++++-- .../test/exporters/agent/exporter.spec.js | 16 ++++++++++++++++ 2 files changed, 25 insertions(+), 2 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index 744080acc93..9019120d530 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -58,9 +58,16 @@ class AgentExporter { flush (done = () => {}) { clearTimeout(this.#timer) this.#timer = undefined - this.#flush() - const activeFlushes = [...this.#activeFlushes] + // Snapshot before the boundary flush so a failed encoding cannot cause a + // Vercel lifecycle flush to abandon exports that were already in flight. + let activeFlushes = [...this.#activeFlushes] + try { + this.#flush() + } catch (error) { + log.error('Failed to flush traces: %s', error.message) + } + activeFlushes = [...new Set([...activeFlushes, ...this.#activeFlushes])] if (activeFlushes.length === 0) return done() let pending = activeFlushes.length diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index 40bc80d83e3..b699220d8a3 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -140,6 +140,22 @@ describe('Exporter', () => { sinon.assert.calledOnce(flushed) }) + + it('waits for an earlier export when the boundary flush fails', () => { + let inFlightDone + writer.flush = sinon.stub() + writer.flush.onFirstCall().callsFake(done => { inFlightDone = done }) + writer.flush.onSecondCall().throws(new Error('encode failed')) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + exporter.export([span]) + exporter.flush(flushed) + + sinon.assert.notCalled(flushed) + inFlightDone() + sinon.assert.calledOnce(flushed) + }) }) describe('setUrl', () => { From 737014149a29b63d7e858feec814ac6b56a79e40 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 16:10:09 -0400 Subject: [PATCH 15/31] fix(serverless): retain telemetry on Vercel --- .github/CODEOWNERS | 1 + .../datadog-plugin-http2/test/server.spec.js | 14 ++ .../src/exporters/span-stats/index.js | 4 +- packages/dd-trace/src/flush.js | 65 +++++++++ .../opentelemetry/logs/batch_log_processor.js | 18 ++- .../dd-trace/src/opentelemetry/logs/index.js | 6 + .../src/opentelemetry/logs/logger_provider.js | 11 +- .../src/opentelemetry/metrics/index.js | 5 + .../opentelemetry/metrics/meter_provider.js | 8 ++ .../metrics/otlp_http_metric_exporter.js | 6 +- .../metrics/otlp_span_stats_exporter.js | 6 +- .../metrics/periodic_metric_reader.js | 14 +- .../otlp/otlp_http_exporter_base.js | 89 ++++++++---- packages/dd-trace/src/proxy.js | 3 +- packages/dd-trace/src/serverless.js | 87 +++++++++++- packages/dd-trace/src/span_stats.js | 24 +++- packages/dd-trace/src/tracer.js | 9 ++ .../dd-trace/test/opentelemetry/logs.spec.js | 20 +++ .../test/opentelemetry/metrics.spec.js | 23 ++++ .../metrics/otlp_span_stats_exporter.spec.js | 24 ++++ packages/dd-trace/test/proxy.spec.js | 22 +++ packages/dd-trace/test/serverless.spec.js | 130 +++++++++++++++++- packages/dd-trace/test/span_stats.spec.js | 35 +++++ packages/dd-trace/test/tracer.spec.js | 21 +++ 24 files changed, 595 insertions(+), 50 deletions(-) create mode 100644 packages/dd-trace/src/flush.js diff --git a/.github/CODEOWNERS b/.github/CODEOWNERS index f5e2064912a..d7da782762d 100644 --- a/.github/CODEOWNERS +++ b/.github/CODEOWNERS @@ -62,6 +62,7 @@ /packages/dd-trace/src/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/src/azure_metadata.js @DataDog/apm-serverless /packages/dd-trace/src/serverless.js @DataDog/apm-serverless +/packages/dd-trace/src/flush.js @DataDog/apm-serverless @DataDog/apm-sdk-capabilities-js /packages/dd-trace/test/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/test/azure_metadata.spec.js @DataDog/apm-serverless /packages/dd-trace/test/serverless.spec.js @DataDog/apm-serverless diff --git a/packages/datadog-plugin-http2/test/server.spec.js b/packages/datadog-plugin-http2/test/server.spec.js index ee4c52be7da..3358c024735 100644 --- a/packages/datadog-plugin-http2/test/server.spec.js +++ b/packages/datadog-plugin-http2/test/server.spec.js @@ -9,6 +9,7 @@ const { setImmediate } = require('node:timers/promises') const { afterEach, beforeEach, describe, it } = require('mocha') const sinon = require('sinon') +const { channel } = require('dc-polyfill') const agent = require('../../dd-trace/test/plugins/agent') const web = require('../../dd-trace/src/plugins/util/web') @@ -309,6 +310,19 @@ describe('Plugin', () => { rawExpectedSchema.server ) + it('publishes a close response event', async () => { + const emit = sinon.spy() + const emitChannel = channel('apm:http2:server:response:emit') + emitChannel.subscribe(emit) + + try { + await request(http2, `http://localhost:${port}/user`) + sinon.assert.calledWithMatch(emit, { eventName: 'close' }) + } finally { + emitChannel.unsubscribe(emit) + } + }) + it('should do automatic instrumentation', done => { agent .assertFirstTraceSpan({ diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 9fa10de4f8a..eddfc42bf5f 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -8,9 +8,9 @@ class SpanStatsExporter { this._writer = new Writer({ url: this._url }) } - export (payload) { + export (payload, done) { this._writer.append(payload) - this._writer.flush() + this._writer.flush(done) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js new file mode 100644 index 00000000000..9cc5ef73f15 --- /dev/null +++ b/packages/dd-trace/src/flush.js @@ -0,0 +1,65 @@ +'use strict' + +/** + * @typedef {(done: () => void) => void | Promise} TelemetryFlusher + */ + +/** @type {Set} */ +const telemetryFlushers = new Set() + +/** + * Registers a configured telemetry pipeline for lifecycle flushing. + * @param {TelemetryFlusher} flusher + * @returns {() => void} Removes the telemetry flusher. + */ +function registerTelemetryFlusher (flusher) { + telemetryFlushers.add(flusher) + return () => telemetryFlushers.delete(flusher) +} + +/** + * Flushes the trace exporter and every registered telemetry pipeline. + * @param {{ + * _exporter?: { flush?: TelemetryFlusher }, + * _processor?: { _stats?: { forceFlush?: TelemetryFlusher } } + * }|undefined} tracer + * @param {() => void} [done] + */ +function flushAll (tracer, done) { + const traceExporter = tracer?._exporter + const traceFlusher = traceExporter?.flush + const spanStatsFlusher = tracer?._processor?._stats?.forceFlush + let pending = telemetryFlushers.size + + (typeof traceFlusher === 'function' ? 1 : 0) + + (typeof spanStatsFlusher === 'function' ? 1 : 0) + if (pending === 0) return done?.() + + const complete = () => { + if (--pending === 0) done?.() + } + + const flush = flusher => { + let flushed = false + const onFlushed = () => { + if (flushed) return + flushed = true + complete() + } + try { + const result = flusher(onFlushed) + result?.then(onFlushed, onFlushed) + } catch { + onFlushed() + } + } + + if (typeof traceFlusher === 'function') { + flush(done => traceFlusher.call(traceExporter, done)) + } + if (typeof spanStatsFlusher === 'function') { + flush(done => spanStatsFlusher.call(tracer._processor._stats, done)) + } + for (const flusher of telemetryFlushers) flush(flusher) +} + +module.exports = { flushAll, registerTelemetryFlusher } diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 46e8ba6c16a..9dc1b60773f 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -54,10 +54,21 @@ class BatchLogRecordProcessor { /** * Forces an immediate flush of all pending log records. - * @returns {undefined} Promise that resolves when flush is complete + * @param {Function} [done] Called after all pending log exports complete */ - forceFlush () { - this.#export() + forceFlush (done) { + this.#clearTimer() + const flushNext = () => { + if (this.#logRecords.length === 0) { + if (typeof this.exporter.flush === 'function') this.exporter.flush(done) + else done?.() + return + } + + const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) + this.exporter.export(logRecords, flushNext) + } + flushNext() } /** @@ -79,6 +90,7 @@ class BatchLogRecordProcessor { * @private */ #export () { + if (this.#logRecords.length === 0) return const logRecords = this.#logRecords.slice(0, this.#maxExportBatchSize) this.#logRecords = this.#logRecords.slice(this.#maxExportBatchSize) diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index d6a40ad0122..c98773e39ab 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -27,10 +27,13 @@ const os = require('os') * @package */ +const { registerTelemetryFlusher } = require('../../flush') const LoggerProvider = require('./logger_provider') const BatchLogRecordProcessor = require('./batch_log_processor') const OtlpHttpLogExporter = require('./otlp_http_log_exporter') +let unregisterTelemetryFlusher + /** * Initializes OpenTelemetry Logs support * @param {import('../../config/config-base')} config - Tracer configuration instance @@ -79,6 +82,9 @@ function initializeOpenTelemetryLogs (config) { // Register the logger provider globally with OpenTelemetry API loggerProvider.register() + // Retain only the current global provider when the tracer reinitializes. + unregisterTelemetryFlusher?.() + unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } module.exports = { diff --git a/packages/dd-trace/src/opentelemetry/logs/logger_provider.js b/packages/dd-trace/src/opentelemetry/logs/logger_provider.js index 820d3da574f..81a2cf340a4 100644 --- a/packages/dd-trace/src/opentelemetry/logs/logger_provider.js +++ b/packages/dd-trace/src/opentelemetry/logs/logger_provider.js @@ -84,12 +84,15 @@ class LoggerProvider { /** * Forces a flush of all pending log records. - * @returns {undefined} Promise that resolves when flush is n ssue cncomplete + * @param {Function} [done] Called after all pending log exports complete */ - forceFlush () { - if (!this.isShutdown) { - return this.processor?.forceFlush() + forceFlush (done) { + if (this.isShutdown || !this.processor) { + done?.() + return } + + this.processor.forceFlush(done) } /** diff --git a/packages/dd-trace/src/opentelemetry/metrics/index.js b/packages/dd-trace/src/opentelemetry/metrics/index.js index 20c6d424f06..820f2116f77 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/index.js +++ b/packages/dd-trace/src/opentelemetry/metrics/index.js @@ -6,11 +6,13 @@ const { metrics } = require('@opentelemetry/api') const { VERSION } = require('../../../../../version') const processTags = require('../../process-tags') +const { registerTelemetryFlusher } = require('../../flush') const MeterProvider = require('./meter_provider') const PeriodicMetricReader = require('./periodic_metric_reader') const OtlpHttpMetricExporter = require('./otlp_http_metric_exporter') const RESERVED_TRACER_TAGS = new Set(['service', 'env', 'version', 'runtime_id', 'runtime-id']) +let unregisterTelemetryFlusher /** * @typedef {import('../../config')} Config @@ -78,6 +80,9 @@ function initializeOpenTelemetryMetrics (config) { const meterProvider = new MeterProvider({ reader }) metrics.setGlobalMeterProvider(meterProvider) + // Retain only the current global provider when the tracer reinitializes. + unregisterTelemetryFlusher?.() + unregisterTelemetryFlusher = registerTelemetryFlusher(done => meterProvider.forceFlush(done)) } /** diff --git a/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js b/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js index ebc9eeb1910..53cfcb20a57 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js +++ b/packages/dd-trace/src/opentelemetry/metrics/meter_provider.js @@ -49,6 +49,14 @@ class MeterProvider { } return meter } + + /** + * @param {Function} [done] Called after the metric export completes + */ + forceFlush (done) { + if (this.reader) this.reader.forceFlush(done) + else done?.() + } } module.exports = MeterProvider diff --git a/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js b/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js index 8af42b70854..3bd2b305d03 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js +++ b/packages/dd-trace/src/opentelemetry/metrics/otlp_http_metric_exporter.js @@ -34,10 +34,11 @@ class OtlpHttpMetricExporter extends OtlpHttpExporterBase { * * @param {Map} metrics - Map of metric data to export * - * @returns {void} + * @param {Function} [done] Called after the HTTP export completes */ - export (metrics) { + export (metrics, done) { if (metrics.size === 0) { + done?.({ code: 0 }) return } @@ -56,6 +57,7 @@ class OtlpHttpMetricExporter extends OtlpHttpExporterBase { if (result.code === 0) { this.recordTelemetry('otel.metrics_export_successes', 1, additionalTags) } + done?.(result) }) } } diff --git a/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js b/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js index b7809e00ffd..890f1ba1953 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js +++ b/packages/dd-trace/src/opentelemetry/metrics/otlp_span_stats_exporter.js @@ -22,14 +22,16 @@ class OtlpStatsExporter extends OtlpHttpExporterBase { /** * @param {Array<{timeNs: number, bucket: import('../../span_stats').SpanBuckets}>} drained * @param {number} bucketSizeNs + * @param {Function} [done] Called after the HTTP export completes */ - export (drained, bucketSizeNs) { - if (drained.length === 0) return + export (drained, bucketSizeNs, done) { + if (drained.length === 0) return done?.() const payload = this.#transformer.transform(drained, bucketSizeNs) this.sendPayload(payload, (result) => { if (result.code !== 0) { log.error('Failed to export span stats: %s', result.error?.message) } + done?.() }) } } diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index a97b5cb6c99..e3ede3d0744 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -197,14 +197,18 @@ class PeriodicMetricReader { /** * Forces an immediate collection and export of all metrics. - * @returns {void} + * @param {Function} [done] Called after the metric export completes */ - forceFlush () { + forceFlush (done) { if (this.#isShutdown) { log.warn('PeriodicMetricReader is shutdown. %d measurement(s) were dropped', this.#droppedCount) + done?.() return } - this.#collectAndExport() + this.#collectAndExport(() => { + if (typeof this.exporter.flush === 'function') this.exporter.flush(done) + else done?.() + }) } /** @@ -250,7 +254,7 @@ class PeriodicMetricReader { * * @param {Function} [callback] - Called after export completes */ - #collectAndExport (callback = () => {}) { + #collectAndExport (callback) { // Atomically drain measurements for export. New measurements can be recorded // during export without interfering with this batch. const allMeasurements = this.#measurements @@ -292,7 +296,7 @@ class PeriodicMetricReader { } if (allMeasurements.length === 0) { - callback() + callback?.() return } diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index fe27cb643dd..696307680bc 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -20,6 +20,8 @@ const legacyStorage = storage('legacy') */ class OtlpHttpExporterBase { #transport = https + #activeRequests = 0 + #flushCallbacks = [] /** * Creates a new OtlpHttpExporterBase instance. @@ -88,39 +90,76 @@ class OtlpHttpExporterBase { }, } - legacyStorage.run({ noop: true }, () => { - const req = this.#transport.request(options, (res) => { - let data = '' + this.#activeRequests++ + let completed = false + const complete = result => { + if (completed) return + completed = true + this.#activeRequests-- + resultCallback(result) + if (this.#activeRequests === 0) this.#completeFlush() + } - res.on('data', (chunk) => { - data += chunk + try { + legacyStorage.run({ noop: true }, () => { + const req = this.#transport.request(options, (res) => { + let data = '' + + res.on('data', (chunk) => { + data += chunk + }) + + res.once('error', (error) => { + complete({ code: 1, error }) + }) + + res.once('end', () => { + // @ts-expect-error - res.statusCode can be undefined + if (res.statusCode >= 200 && res.statusCode < 300) { + complete({ code: 0 }) + } else { + const error = new Error(`HTTP ${res.statusCode}: ${data}`) + complete({ code: 1, error }) + } + }) }) - res.once('end', () => { - // @ts-expect-error - res.statusCode can be undefined - if (res.statusCode >= 200 && res.statusCode < 300) { - resultCallback({ code: 0 }) - } else { - const error = new Error(`HTTP ${res.statusCode}: ${data}`) - resultCallback({ code: 1, error }) - } + req.on('error', (error) => { + log.error('Error sending OTLP %s:', this.signalType, error) + complete({ code: 1, error }) }) - }) - req.on('error', (error) => { - log.error('Error sending OTLP %s:', this.signalType, error) - resultCallback({ code: 1, error }) - }) + req.once('timeout', () => { + req.destroy() + const error = new Error('Request timeout') + complete({ code: 1, error }) + }) - req.once('timeout', () => { - req.destroy() - const error = new Error('Request timeout') - resultCallback({ code: 1, error }) + req.write(payload) + req.end() }) + } catch (error) { + complete({ code: 1, error }) + } + } + + /** + * Calls back once all started OTLP requests have completed. + * @param {Function} [done] + */ + flush (done) { + if (!done) return + if (this.#activeRequests === 0) { + done() + return + } + this.#flushCallbacks.push(done) + } - req.write(payload) - req.end() - }) + #completeFlush () { + const callbacks = this.#flushCallbacks + this.#flushCallbacks = [] + for (const callback of callbacks) callback() } /** diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 3330061d831..30cb399c6bf 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -12,7 +12,7 @@ const telemetry = require('./telemetry') const nomenclature = require('./service-naming') const PluginManager = require('./plugin_manager') const NoopDogStatsDClient = require('./noop/dogstatsd') -const { IS_SERVERLESS } = require('./serverless') +const { IS_SERVERLESS, initializeServerlessTelemetry } = require('./serverless') const processTags = require('./process-tags') const { isTrue } = require('./util') const { @@ -389,6 +389,7 @@ class Tracer extends NoopProxy { if (this._tracingInitialized) { this._tracer.configure(config) this._pluginManager.configure(config) + initializeServerlessTelemetry(this._tracer) DynamicInstrumentation.configure(config) setStartupLogPluginManager(this._pluginManager) startupLog() diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 23e424b4baa..91e08e98826 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -1,7 +1,12 @@ 'use strict' +const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') +const nextRequestFinishChannel = channel('apm:next:request:finish') +const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const vercelRetentionHandlers = new WeakMap() + function getIsGCPFunction () { const isDeprecatedGCPFunction = getEnvironmentVariable('FUNCTION_NAME') !== undefined && @@ -45,14 +50,89 @@ function isInServerlessEnvironment () { /** * Gets tags describing the serverless platform where the tracer is running. * + * @param {{ isVercel: boolean }} [platform] Detected serverless platform. * @returns {string[]|undefined} */ -function getServerlessPlatformTags () { - if (getEnvironmentVariable('VERCEL') === '1') { +function getServerlessPlatformTags (platform = getServerlessPlatform()) { + if (platform.isVercel) { return getVercelPlatformTags() } } +/** + * Detects the serverless platform once while configuration is built. + * @returns {{ isVercel: boolean }} + */ +function getServerlessPlatform () { + return { isVercel: getEnvironmentVariable('VERCEL') === '1' } +} + +/** + * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + */ + +/** + * @param {TelemetryFlusher} tracer + * @param {() => void} done + * @returns {void} + */ +function flushVercelTelemetry (tracer, done) { + setImmediate(() => { + try { + tracer.flushAll(done) + } catch { + done() + } + }) +} + +function registerVercelRequestFlush (tracer) { + const waitUntil = getVercelRequestContext()?.waitUntil + if (typeof waitUntil !== 'function') return + + // Retain the invocation synchronously, then flush after Next finishes its root span. + let done + const pending = new Promise(resolve => { done = resolve }) + try { + waitUntil(pending) + flushVercelTelemetry(tracer, done) + } catch { + done() + } +} + +function getVercelRequestContext () { + return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() +} + +/** + * @param {TelemetryFlusher} tracer + * @returns {(() => void)|undefined} + */ +function registerVercelTelemetryRetention (tracer) { + const existing = vercelRetentionHandlers.get(tracer) + if (existing) return existing + + if (typeof tracer?.flushAll !== 'function') return + const flushRequest = () => registerVercelRequestFlush(tracer) + nextRequestFinishChannel.subscribe(flushRequest) + + const unregister = () => { + nextRequestFinishChannel.unsubscribe(flushRequest) + vercelRetentionHandlers.delete(tracer) + } + vercelRetentionHandlers.set(tracer, unregister) + return unregister +} + +/** + * Registers the lifecycle adapter selected by the detected serverless platform. + * @param {TelemetryFlusher} tracer + */ +function initializeServerlessTelemetry (tracer) { + if (getServerlessPlatform().isVercel) registerVercelTelemetryRetention(tracer) +} + /** * @returns {string[]|undefined} */ @@ -80,9 +160,12 @@ function getVercelPlatformTags () { module.exports = { getServerlessPlatformTags, + getServerlessPlatform, getIsGCPFunction, getIsAzureFunction, enableGCPPubSubPushSubscription, getIsFlexConsumptionAzureFunction, + registerVercelTelemetryRetention, + initializeServerlessTelemetry, IS_SERVERLESS: isInServerlessEnvironment(), } diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index e5f66588eb6..d35d3798fa8 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -235,6 +235,18 @@ class SpanStatsProcessor { } onInterval () { + this.#flush() + } + + /** + * Drains pending span statistics and waits for their export. + * @param {Function} [done] + */ + forceFlush (done) { + this.#flush(done) + } + + #flush (done) { const drained = this.#drainBuckets() if (this.enabled && !this.otlpExporter) { @@ -248,10 +260,16 @@ class SpanStatsProcessor { RuntimeID: this.tags['runtime-id'], Sequence: ++this.sequence, ProcessTags: processTags.serialized, - }) + }, done) } else if (this.otlpExporter && drained.length > 0) { - this.otlpExporter.export(drained, this.bucketSizeNs) - } + this.otlpExporter.export(drained, this.bucketSizeNs, () => { + if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) + else done?.() + }) + } else if (this.otlpExporter) { + if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) + else done?.() + } else done?.() } onSpanFinished (span) { diff --git a/packages/dd-trace/src/tracer.js b/packages/dd-trace/src/tracer.js index 28e7df78d5f..608dc5c2778 100644 --- a/packages/dd-trace/src/tracer.js +++ b/packages/dd-trace/src/tracer.js @@ -13,6 +13,7 @@ const { isError } = require('./util') const { setStartupLogConfig } = require('./startup-log') const { DataStreamsCheckpointer, DataStreamsManager, DataStreamsProcessor } = require('./datastreams') const { IS_SERVERLESS } = require('./serverless') +const { flushAll } = require('./flush') const log = require('./log') // Always-on writer (console.warn), not the channel-gated `log`: these surface regardless of // DD_TRACE_DEBUG. @@ -150,6 +151,14 @@ class DatadogTracer extends Tracer { this._dataStreamsProcessor.setUrl(url) } + /** + * Flushes every configured telemetry pipeline. + * @param {Function} [done] Called after every configured export completes + */ + flushAll (done) { + flushAll(this, done) + } + scope () { return this._scope } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index 3928372c6c9..f79e25865ae 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -15,6 +15,7 @@ require('../setup/core') const { protoLogsService } = require('../../src/opentelemetry/otlp/protobuf_loader').getProtobufTypes() const { getConfigFresh } = require('../helpers/config') const { assertObjectContains } = require('../../../../integration-tests/helpers') +const BatchLogRecordProcessor = require('../../src/opentelemetry/logs/batch_log_processor') /** * @param {object} type protobufjs Type instance for the OTLP service message @@ -142,6 +143,25 @@ describe('OpenTelemetry Logs', () => { }) describe('Logs Export', () => { + it('waits for an in-flight export during forceFlush', () => { + let exportDone + let flushDone + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { exportDone = done }, + flush: (done) => { flushDone = done }, + }, 60_000, 1) + const done = sinon.spy() + + processor.onEmit({ body: 'in flight' }, { name: 'test' }) + processor.forceFlush(done) + + sinon.assert.notCalled(done) + exportDone({ code: 0 }) + sinon.assert.notCalled(done) + flushDone() + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] diff --git a/packages/dd-trace/test/opentelemetry/metrics.spec.js b/packages/dd-trace/test/opentelemetry/metrics.spec.js index 0ad70fbdc51..3d55684b41c 100644 --- a/packages/dd-trace/test/opentelemetry/metrics.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics.spec.js @@ -13,6 +13,8 @@ require('../setup/core') const { protoMetricsService } = require('../../src/opentelemetry/otlp/protobuf_loader').getProtobufTypes() const { getConfigFresh } = require('../helpers/config') const { DEFAULT_MAX_MEASUREMENT_QUEUE_SIZE } = require('../../src/opentelemetry/metrics/constants') +const MeterProvider = require('../../src/opentelemetry/metrics/meter_provider') +const PeriodicMetricReader = require('../../src/opentelemetry/metrics/periodic_metric_reader') /** * @param {object} type protobufjs Type instance for the OTLP service message @@ -661,6 +663,27 @@ describe('OpenTelemetry Meter Provider', () => { }) describe('Lifecycle', () => { + it('waits for an in-flight export during forceFlush', () => { + let exportDone + let flushDone + const reader = new PeriodicMetricReader({ + export: (metrics, done) => { exportDone = done }, + flush: (done) => { flushDone = done }, + }, 60_000, 'DELTA', 1024) + const meter = new MeterProvider({ reader }).getMeter('test') + const done = sinon.spy() + + meter.createCounter('in-flight').add(1) + reader.forceFlush(done) + + sinon.assert.notCalled(done) + exportDone({ code: 0 }) + sinon.assert.notCalled(done) + flushDone() + sinon.assert.calledOnce(done) + reader.shutdown() + }) + it('handles shutdown gracefully', async () => { setupMetrics() const provider = metrics.getMeterProvider() diff --git a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js index ccceb847fd6..a1cd46eb3b4 100644 --- a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js @@ -218,4 +218,28 @@ describe('OtlpStatsExporter', () => { exporter.export(drained, BUCKET_SIZE_NS) assert.ok(httpStub.calledOnce) }) + + it('flushes after an in-flight HTTP export completes', () => { + let onEnd + httpStub.callsFake((options, callback) => { + const mockRes = { + statusCode: 200, + on: sinon.stub(), + once: (event, handler) => { + if (event === 'end') onEnd = handler + return mockRes + }, + } + callback(mockRes) + return mockReq + }) + const flushed = sinon.spy() + + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + exporter.flush(flushed) + + sinon.assert.notCalled(flushed) + onEnd() + sinon.assert.calledOnce(flushed) + }) }) diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index bd24e4454c0..b48cb7d06cb 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -269,6 +269,28 @@ describe('TracerProxy', () => { './flare': flare, './openfeature': openfeature, './openfeature/flagging_provider': OpenFeatureProvider, + './serverless': { + IS_SERVERLESS: false, + }, + }) + + const { enable: openfeatureRcEnable } = require('../src/openfeature/remote_config') + const noopOpenfeature = {} + + featureRegistry.registerFeature({ + name: 'openfeature', + noop: noopOpenfeature, + factory: () => openfeature, + provider: () => OpenFeatureProvider, + /** @param {object} config */ + isEnabled (config) { + return config.featureFlags.DD_FEATURE_FLAGS_ENABLED + }, + remoteConfig (rc, config, proxy) { + const subscribe = config.featureFlags.DD_FEATURE_FLAGS_ENABLED && + config.featureFlags.DD_FEATURE_FLAGS_CONFIGURATION_SOURCE === 'remote_config' + openfeatureRcEnable(rc, () => proxy.openfeature, subscribe) + }, }) proxy = new ProxyClass() diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index d33923f932b..a3c52edc412 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -1,13 +1,27 @@ 'use strict' const assert = require('node:assert/strict') +const http = require('node:http') const { describe, it, afterEach } = require('mocha') +const { logs } = require('@opentelemetry/api-logs') +const { metrics } = require('@opentelemetry/api') +const { channel } = require('dc-polyfill') require('./setup/core') -const { getServerlessPlatformTags, enableGCPPubSubPushSubscription } = require('../src/serverless') +const { + getServerlessPlatformTags, + getServerlessPlatform, + enableGCPPubSubPushSubscription, + registerVercelTelemetryRetention, + initializeServerlessTelemetry, +} = require('../src/serverless') +const Tracer = require('../src/tracer') +const { initializeOpenTelemetryLogs } = require('../src/opentelemetry/logs') +const { initializeOpenTelemetryMetrics } = require('../src/opentelemetry/metrics') const agent = require('./plugins/agent') +const { getConfigFresh } = require('./helpers/config') describe('enableGCPPubSubPushSubscription', () => { const originalKService = process.env.K_SERVICE @@ -121,4 +135,118 @@ describe('Vercel span metadata', () => { 'vercel.environment', 'preview', ]) }) + + it('records the Vercel environment in configuration', () => { + process.env = { ...environment, VERCEL: '1' } + + assert.strictEqual(getServerlessPlatform().isVercel, true) + }) +}) + +describe('Vercel telemetry retention', () => { + const requestContext = Symbol.for('@vercel/request-context') + const originalContext = globalThis[requestContext] + const endpointVariables = [ + 'VERCEL', + 'OTEL_TRACES_EXPORTER', + 'DD_LOGS_OTEL_ENABLED', + 'DD_METRICS_OTEL_ENABLED', + 'OTEL_EXPORTER_OTLP_TRACES_ENDPOINT', + 'OTEL_EXPORTER_OTLP_LOGS_ENDPOINT', + 'OTEL_EXPORTER_OTLP_METRICS_ENDPOINT', + ] + const originalEndpoints = Object.fromEntries(endpointVariables.map(name => [name, process.env[name]])) + + afterEach(() => { + if (originalContext === undefined) delete globalThis[requestContext] + else globalThis[requestContext] = originalContext + for (const name of endpointVariables) { + if (originalEndpoints[name] === undefined) delete process.env[name] + else process.env[name] = originalEndpoints[name] + } + logs.disable() + metrics.disable() + }) + + it('retains trace, log, and metric payloads until their intake responses complete', async () => { + process.env.OTEL_TRACES_EXPORTER = 'otlp' + process.env.DD_LOGS_OTEL_ENABLED = 'true' + process.env.DD_METRICS_OTEL_ENABLED = 'true' + const received = new Set() + let intakeReceived + let metricPayloads = 0 + const intake = http.createServer((req, res) => { + req.resume() + req.once('end', () => { + if (req.url === '/v1/logs') received.add('logs') + if (req.url === '/v1/metrics') { + received.add('metrics') + metricPayloads++ + } + if (req.url === '/v1/traces') received.add('traces') + res.end() + if (received.size === 3 && metricPayloads === 2) intakeReceived() + }) + }) + await new Promise(resolve => intake.listen(0, '127.0.0.1', resolve)) + const { port } = intake.address() + const endpoint = `http://127.0.0.1:${port}` + process.env.OTEL_EXPORTER_OTLP_TRACES_ENDPOINT = `${endpoint}/v1/traces` + process.env.OTEL_EXPORTER_OTLP_LOGS_ENDPOINT = `${endpoint}/v1/logs` + process.env.OTEL_EXPORTER_OTLP_METRICS_ENDPOINT = `${endpoint}/v1/metrics` + + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + const intakeRequests = new Promise(resolve => { intakeReceived = resolve }) + + let unregister + try { + const config = getConfigFresh({ service: 'serverless-flush' }) + const tracer = new Tracer(config) + initializeOpenTelemetryLogs(config) + initializeOpenTelemetryMetrics(config) + + tracer.trace('serverless.flush', {}, () => {}) + logs.getLogger('serverless-flush').emit({ body: 'flush me' }) + metrics.getMeter('serverless-flush').createCounter('flush.me').add(1) + + unregister = registerVercelTelemetryRetention(tracer) + channel('apm:next:request:finish').publish({}) + await Promise.race([ + intakeRequests, + new Promise((_resolve, reject) => setTimeout(() => reject(new Error('Missing intake signals')), 1000)), + ]) + await retained + assert.deepStrictEqual(received, new Set(['traces', 'logs', 'metrics'])) + assert.strictEqual(metricPayloads, 2) + } finally { + unregister?.() + metrics.getMeterProvider()?.reader?.shutdown() + logs.getLoggerProvider()?.shutdown?.() + await new Promise(resolve => intake.close(resolve)) + } + }) + + it('defers flushing until after Next request finish subscribers return', async () => { + process.env.VERCEL = '1' + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + const finishChannel = channel('apm:next:request:finish') + let finished = false + const tracer = { + flushAll (done) { + assert.ok(finished) + done() + }, + } + + initializeServerlessTelemetry(tracer) + finishChannel.publish({}) + finished = true + await retained + }) }) diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index 3652c8fe168..8ff17ca97fa 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -87,6 +87,7 @@ const SpanStatsExporter = sinon.stub().returns(exporter) const otlpExporter = { export: sinon.stub(), + flush: sinon.stub(), } const { @@ -643,6 +644,40 @@ describe('SpanStatsProcessor', () => { assert.ok(otlpExporter.export.calledOnce) }) + it('force flushes pending OTLP span statistics', () => { + const exporter = { + export: sinon.stub().callsFake((_drained, _bucketSizeNs, done) => done()), + flush: sinon.stub().callsFake(done => done()), + } + const p = new SpanStatsProcessor(config, exporter) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) + assert.ok(flushed) + assert.strictEqual(p.buckets.size, 0) + }) + + it('force flushes pending agent span statistics', () => { + exporter.export.resetHistory() + exporter.export.callsFake((_payload, done) => done()) + const p = new SpanStatsProcessor(config) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(flushed) + assert.strictEqual(p.buckets.size, 0) + exporter.export.resetBehavior() + }) + it('should record spans when only OTLP is enabled', () => { otlpExporter.export.resetHistory() const p = new SpanStatsProcessor({ diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index ee9c4d5ec05..d108e3dcf05 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -50,6 +50,27 @@ describe('Tracer', () => { }) }) + describe('flushAll', () => { + it('flushes registered telemetry pipelines with the configured trace exporter', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + const tracer = { + _exporter: { + flush: sinon.stub().callsFake(done => done()), + }, + } + const telemetryFlusher = sinon.stub().callsFake(done => done()) + const unregister = registerTelemetryFlusher(telemetryFlusher) + let completed = false + + flushAll(tracer, () => { completed = true }) + + sinon.assert.calledOnce(tracer._exporter.flush) + sinon.assert.calledOnce(telemetryFlusher) + assert.strictEqual(completed, true) + unregister() + }) + }) + describe('trace', () => { it('should run the callback with a new span', () => { tracer.trace('name', {}, span => { From dcb9d69347eda055e7b31a7456eee899a80d0760 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 21:45:55 -0400 Subject: [PATCH 16/31] fix(serverless): retain active telemetry exports --- .../dd-trace/src/exporters/agent/index.js | 25 +++++++- packages/dd-trace/src/flush.js | 11 ++-- .../opentelemetry/logs/batch_log_processor.js | 1 + .../metrics/periodic_metric_reader.js | 1 + .../otlp/otlp_http_exporter_base.js | 27 ++++---- packages/dd-trace/src/serverless.js | 26 ++++++-- .../test/exporters/agent/exporter.spec.js | 17 +++++ .../metrics/otlp_span_stats_exporter.spec.js | 26 ++++++++ packages/dd-trace/test/serverless.spec.js | 64 +++++++++++++++++-- 9 files changed, 169 insertions(+), 29 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index e951048ab5b..b69706fc12e 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -6,6 +6,7 @@ const Writer = require('./writer') class AgentExporter { #timer + #activeFlushes = new Set() constructor (config, prioritySampler) { this._config = config @@ -44,10 +45,10 @@ class AgentExporter { const { flushInterval } = this._config if (flushInterval === 0) { - this._writer.flush() + this.#flush() } else if (this.#timer === undefined) { this.#timer = setTimeout(() => { - this._writer.flush() + this.#flush() this.#timer = undefined }, flushInterval) this.#timer.unref?.() @@ -57,7 +58,25 @@ class AgentExporter { flush (done = () => {}) { clearTimeout(this.#timer) this.#timer = undefined - this._writer.flush(done) + this.#flush() + + const activeFlushes = [...this.#activeFlushes] + if (activeFlushes.length === 0) return done() + + let pending = activeFlushes.length + const complete = () => { + if (--pending === 0) done() + } + for (const flush of activeFlushes) flush.callbacks.push(complete) + } + + #flush () { + const flush = { callbacks: [] } + this.#activeFlushes.add(flush) + this._writer.flush(() => { + this.#activeFlushes.delete(flush) + for (const callback of flush.callbacks) callback() + }) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 9cc5ef73f15..6fe4a10743d 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -1,5 +1,7 @@ 'use strict' +const log = require('./log') + /** * @typedef {(done: () => void) => void | Promise} TelemetryFlusher */ @@ -40,16 +42,17 @@ function flushAll (tracer, done) { const flush = flusher => { let flushed = false - const onFlushed = () => { + const onFlushed = error => { if (flushed) return flushed = true + if (error) log.error('Error flushing telemetry pipeline:', error) complete() } try { const result = flusher(onFlushed) - result?.then(onFlushed, onFlushed) - } catch { - onFlushed() + result?.then(onFlushed, error => onFlushed(error)) + } catch (error) { + onFlushed(error) } } diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 9dc1b60773f..370e7066aa8 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -60,6 +60,7 @@ class BatchLogRecordProcessor { this.#clearTimer() const flushNext = () => { if (this.#logRecords.length === 0) { + // A size-triggered batch can still be in flight after it leaves this queue. if (typeof this.exporter.flush === 'function') this.exporter.flush(done) else done?.() return diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index e3ede3d0744..fbf4cab33c9 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -255,6 +255,7 @@ class PeriodicMetricReader { * @param {Function} [callback] - Called after export completes */ #collectAndExport (callback) { + // Observable instruments must be collected even without synchronous measurements. // Atomically drain measurements for export. New measurements can be recorded // during export without interfering with this batch. const allMeasurements = this.#measurements diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index 696307680bc..7b90bff8746 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -20,8 +20,7 @@ const legacyStorage = storage('legacy') */ class OtlpHttpExporterBase { #transport = https - #activeRequests = 0 - #flushCallbacks = [] + #activeRequests = new Set() /** * Creates a new OtlpHttpExporterBase instance. @@ -90,14 +89,15 @@ class OtlpHttpExporterBase { }, } - this.#activeRequests++ + const activeRequest = { callbacks: [] } + this.#activeRequests.add(activeRequest) let completed = false const complete = result => { if (completed) return completed = true - this.#activeRequests-- + this.#activeRequests.delete(activeRequest) resultCallback(result) - if (this.#activeRequests === 0) this.#completeFlush() + for (const callback of activeRequest.callbacks) callback() } try { @@ -144,22 +144,21 @@ class OtlpHttpExporterBase { } /** - * Calls back once all started OTLP requests have completed. + * Calls back once OTLP requests active at the flush boundary have completed. * @param {Function} [done] */ flush (done) { if (!done) return - if (this.#activeRequests === 0) { + const activeRequests = [...this.#activeRequests] + if (activeRequests.length === 0) { done() return } - this.#flushCallbacks.push(done) - } - - #completeFlush () { - const callbacks = this.#flushCallbacks - this.#flushCallbacks = [] - for (const callback of callbacks) callback() + let pending = activeRequests.length + const complete = () => { + if (--pending === 0) done() + } + for (const request of activeRequests) request.callbacks.push(complete) } /** diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 91e08e98826..917e5f97f71 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -4,8 +4,11 @@ const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') const nextRequestFinishChannel = channel('apm:next:request:finish') +const httpRequestFinishChannel = channel('apm:http:server:request:finish') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const VERCEL_FLUSH_TIMEOUT = 2_000 const vercelRetentionHandlers = new WeakMap() +const retainedVercelRequests = new WeakSet() function getIsGCPFunction () { const isDeprecatedGCPFunction = @@ -77,18 +80,31 @@ function getServerlessPlatform () { * @returns {void} */ function flushVercelTelemetry (tracer, done) { + let completed = false + const complete = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done() + } + const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) + setImmediate(() => { try { - tracer.flushAll(done) + tracer.flushAll(complete) } catch { - done() + complete() } }) } function registerVercelRequestFlush (tracer) { - const waitUntil = getVercelRequestContext()?.waitUntil + const requestContext = getVercelRequestContext() + if (!requestContext || retainedVercelRequests.has(requestContext)) return + + const { waitUntil } = requestContext if (typeof waitUntil !== 'function') return + retainedVercelRequests.add(requestContext) // Retain the invocation synchronously, then flush after Next finishes its root span. let done @@ -116,9 +132,11 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) nextRequestFinishChannel.subscribe(flushRequest) + httpRequestFinishChannel.subscribe(flushRequest) const unregister = () => { nextRequestFinishChannel.unsubscribe(flushRequest) + httpRequestFinishChannel.unsubscribe(flushRequest) vercelRetentionHandlers.delete(tracer) } vercelRetentionHandlers.set(tracer, unregister) @@ -130,7 +148,7 @@ function registerVercelTelemetryRetention (tracer) { * @param {TelemetryFlusher} tracer */ function initializeServerlessTelemetry (tracer) { - if (getServerlessPlatform().isVercel) registerVercelTelemetryRetention(tracer) + if (getServerlessPlatform().isVercel) return registerVercelTelemetryRetention(tracer) } /** diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index e9b38fa44b9..1509bc7050a 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -112,6 +112,23 @@ describe('Exporter', () => { }) }) + describe('flush', () => { + it('waits for trace exports already in flight', () => { + const callbacks = [] + writer.flush = sinon.spy(done => callbacks.push(done)) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + exporter.export([span]) + exporter.flush(flushed) + + callbacks[1]() + sinon.assert.notCalled(flushed) + callbacks[0]() + sinon.assert.calledOnce(flushed) + }) + }) + describe('setUrl', () => { beforeEach(() => { exporter = new Exporter({ url }) diff --git a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js index a1cd46eb3b4..84e292bf278 100644 --- a/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics/otlp_span_stats_exporter.spec.js @@ -242,4 +242,30 @@ describe('OtlpStatsExporter', () => { onEnd() sinon.assert.calledOnce(flushed) }) + + it('does not wait for exports started after the flush boundary', () => { + const onEnd = [] + httpStub.callsFake((options, callback) => { + const mockRes = { + statusCode: 200, + on: sinon.stub(), + once: (event, handler) => { + if (event === 'end') onEnd.push(handler) + return mockRes + }, + } + callback(mockRes) + return mockReq + }) + const flushed = sinon.spy() + + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + exporter.flush(flushed) + exporter.export(makeDrained([makeSpan()]), BUCKET_SIZE_NS) + + onEnd[0]() + sinon.assert.calledOnce(flushed) + onEnd[1]() + sinon.assert.calledOnce(flushed) + }) }) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index a3c52edc412..ea489e30954 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -244,9 +244,65 @@ describe('Vercel telemetry retention', () => { }, } - initializeServerlessTelemetry(tracer) - finishChannel.publish({}) - finished = true - await retained + const unregister = initializeServerlessTelemetry(tracer) + try { + finishChannel.publish({}) + finished = true + await retained + } finally { + unregister() + } + }) + + it('retains telemetry for an ordinary HTTP Vercel request only once', async () => { + let retained + let flushes = 0 + const context = { waitUntil: promise => { retained = promise } } + globalThis[requestContext] = { get: () => context } + + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes++ + done() + }, + }) + try { + channel('apm:http:server:request:finish').publish({}) + channel('apm:next:request:finish').publish({}) + await retained + assert.strictEqual(flushes, 1) + } finally { + unregister() + } + }) + + it('bounds Vercel retention when an exporter does not complete', async () => { + let retained + let timeout + const setTimeoutOriginal = global.setTimeout + const clearTimeoutOriginal = global.clearTimeout + global.setTimeout = (callback, duration) => { + timeout = { callback, duration } + return timeout + } + global.clearTimeout = () => {} + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + + let unregister + try { + unregister = registerVercelTelemetryRetention({ flushAll () {} }) + channel('apm:next:request:finish').publish({}) + await new Promise(resolve => setImmediate(resolve)) + + assert.strictEqual(timeout.duration, 2_000) + timeout.callback() + await retained + } finally { + unregister?.() + global.setTimeout = setTimeoutOriginal + global.clearTimeout = clearTimeoutOriginal + } }) }) From 59de657112b1ed95f498361629bbf48018f6cc96 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 21:57:55 -0400 Subject: [PATCH 17/31] refactor(serverless): isolate Vercel lifecycle adapter --- .github/CODEOWNERS | 1 + packages/dd-trace/src/serverless.js | 113 +------------------ packages/dd-trace/src/serverless/vercel.js | 125 +++++++++++++++++++++ packages/dd-trace/test/serverless.spec.js | 8 +- 4 files changed, 134 insertions(+), 113 deletions(-) create mode 100644 packages/dd-trace/src/serverless/vercel.js diff --git a/.github/CODEOWNERS b/.github/CODEOWNERS index d7da782762d..a672a55feaf 100644 --- a/.github/CODEOWNERS +++ b/.github/CODEOWNERS @@ -62,6 +62,7 @@ /packages/dd-trace/src/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/src/azure_metadata.js @DataDog/apm-serverless /packages/dd-trace/src/serverless.js @DataDog/apm-serverless +/packages/dd-trace/src/serverless/vercel.js @DataDog/apm-serverless /packages/dd-trace/src/flush.js @DataDog/apm-serverless @DataDog/apm-sdk-capabilities-js /packages/dd-trace/test/lambda/ @DataDog/serverless-aws @DataDog/apm-serverless /packages/dd-trace/test/azure_metadata.spec.js @DataDog/apm-serverless diff --git a/packages/dd-trace/src/serverless.js b/packages/dd-trace/src/serverless.js index 917e5f97f71..4fc0e94221a 100644 --- a/packages/dd-trace/src/serverless.js +++ b/packages/dd-trace/src/serverless.js @@ -1,15 +1,7 @@ 'use strict' -const { channel } = require('dc-polyfill') const { getEnvironmentVariable, getValueFromEnvSources } = require('./config/helper') -const nextRequestFinishChannel = channel('apm:next:request:finish') -const httpRequestFinishChannel = channel('apm:http:server:request:finish') -const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') -const VERCEL_FLUSH_TIMEOUT = 2_000 -const vercelRetentionHandlers = new WeakMap() -const retainedVercelRequests = new WeakSet() - function getIsGCPFunction () { const isDeprecatedGCPFunction = getEnvironmentVariable('FUNCTION_NAME') !== undefined && @@ -58,7 +50,7 @@ function isInServerlessEnvironment () { */ function getServerlessPlatformTags (platform = getServerlessPlatform()) { if (platform.isVercel) { - return getVercelPlatformTags() + return require('./serverless/vercel').getVercelPlatformTags() } } @@ -70,110 +62,14 @@ function getServerlessPlatform () { return { isVercel: getEnvironmentVariable('VERCEL') === '1' } } -/** - * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher - */ - -/** - * @param {TelemetryFlusher} tracer - * @param {() => void} done - * @returns {void} - */ -function flushVercelTelemetry (tracer, done) { - let completed = false - const complete = () => { - if (completed) return - completed = true - clearTimeout(timeout) - done() - } - const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) - - setImmediate(() => { - try { - tracer.flushAll(complete) - } catch { - complete() - } - }) -} - -function registerVercelRequestFlush (tracer) { - const requestContext = getVercelRequestContext() - if (!requestContext || retainedVercelRequests.has(requestContext)) return - - const { waitUntil } = requestContext - if (typeof waitUntil !== 'function') return - retainedVercelRequests.add(requestContext) - - // Retain the invocation synchronously, then flush after Next finishes its root span. - let done - const pending = new Promise(resolve => { done = resolve }) - try { - waitUntil(pending) - flushVercelTelemetry(tracer, done) - } catch { - done() - } -} - -function getVercelRequestContext () { - return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() -} - -/** - * @param {TelemetryFlusher} tracer - * @returns {(() => void)|undefined} - */ -function registerVercelTelemetryRetention (tracer) { - const existing = vercelRetentionHandlers.get(tracer) - if (existing) return existing - - if (typeof tracer?.flushAll !== 'function') return - const flushRequest = () => registerVercelRequestFlush(tracer) - nextRequestFinishChannel.subscribe(flushRequest) - httpRequestFinishChannel.subscribe(flushRequest) - - const unregister = () => { - nextRequestFinishChannel.unsubscribe(flushRequest) - httpRequestFinishChannel.unsubscribe(flushRequest) - vercelRetentionHandlers.delete(tracer) - } - vercelRetentionHandlers.set(tracer, unregister) - return unregister -} - /** * Registers the lifecycle adapter selected by the detected serverless platform. - * @param {TelemetryFlusher} tracer + * @param {{ flushAll?: (done: () => void) => void }} tracer */ function initializeServerlessTelemetry (tracer) { - if (getServerlessPlatform().isVercel) return registerVercelTelemetryRetention(tracer) -} - -/** - * @returns {string[]|undefined} - */ -function getVercelPlatformTags () { - let tags - const projectId = getEnvironmentVariable('VERCEL_PROJECT_ID') - if (projectId) { - tags = ['vercel.project_id', projectId] - } - - const environment = getEnvironmentVariable('VERCEL_ENV') - if (environment) { - tags ??= [] - tags.push('vercel.environment', environment) - } - - const region = getEnvironmentVariable('VERCEL_REGION') - if (region) { - tags ??= [] - tags.push('vercel.region', region) + if (getServerlessPlatform().isVercel) { + return require('./serverless/vercel').registerVercelTelemetryRetention(tracer) } - - return tags } module.exports = { @@ -183,7 +79,6 @@ module.exports = { getIsAzureFunction, enableGCPPubSubPushSubscription, getIsFlexConsumptionAzureFunction, - registerVercelTelemetryRetention, initializeServerlessTelemetry, IS_SERVERLESS: isInServerlessEnvironment(), } diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js new file mode 100644 index 00000000000..d0e4c20c1ab --- /dev/null +++ b/packages/dd-trace/src/serverless/vercel.js @@ -0,0 +1,125 @@ +'use strict' + +const { channel } = require('dc-polyfill') + +const { getEnvironmentVariable } = require('../config/helper') + +const nextRequestFinishChannel = channel('apm:next:request:finish') +const httpRequestFinishChannel = channel('apm:http:server:request:finish') +const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') +const VERCEL_FLUSH_TIMEOUT = 2_000 +const vercelRetentionHandlers = new WeakMap() +const retainedVercelRequests = new WeakMap() + +/** + * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + */ + +/** + * @param {TelemetryFlusher} tracer + * @param {() => void} done + * @returns {void} + */ +function flushVercelTelemetry (tracer, done) { + let completed = false + const complete = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done() + } + const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) + + setImmediate(() => { + try { + tracer.flushAll(complete) + } catch { + complete() + } + }) +} + +function registerVercelRequestFlush (tracer) { + const requestContext = getVercelRequestContext() + if (!requestContext) return + + const { waitUntil } = requestContext + if (typeof waitUntil !== 'function') return + let retainedTracers = retainedVercelRequests.get(requestContext) + if (!retainedTracers) { + retainedTracers = new WeakSet() + retainedVercelRequests.set(requestContext, retainedTracers) + } + if (retainedTracers.has(tracer)) return + retainedTracers.add(tracer) + + // Retain the invocation synchronously, then flush after Next finishes its root span. + let done + const pending = new Promise(resolve => { done = resolve }) + try { + waitUntil(pending) + flushVercelTelemetry(tracer, done) + } catch { + done() + } +} + +function getVercelRequestContext () { + return globalThis[VERCEL_REQUEST_CONTEXT]?.get?.() +} + +/** + * Retains a Vercel Node Function until configured telemetry exporters complete. + * + * @param {TelemetryFlusher} tracer + * @returns {(() => void)|undefined} + */ +function registerVercelTelemetryRetention (tracer) { + const existing = vercelRetentionHandlers.get(tracer) + if (existing) return existing + + if (typeof tracer?.flushAll !== 'function') return + const flushRequest = () => registerVercelRequestFlush(tracer) + nextRequestFinishChannel.subscribe(flushRequest) + httpRequestFinishChannel.subscribe(flushRequest) + + const unregister = () => { + nextRequestFinishChannel.unsubscribe(flushRequest) + httpRequestFinishChannel.unsubscribe(flushRequest) + vercelRetentionHandlers.delete(tracer) + } + vercelRetentionHandlers.set(tracer, unregister) + return unregister +} + +/** + * Gets Vercel deployment tags to attach to spans. + * + * @returns {string[]|undefined} + */ +function getVercelPlatformTags () { + let tags + const projectId = getEnvironmentVariable('VERCEL_PROJECT_ID') + if (projectId) { + tags = ['vercel.project_id', projectId] + } + + const environment = getEnvironmentVariable('VERCEL_ENV') + if (environment) { + tags ??= [] + tags.push('vercel.environment', environment) + } + + const region = getEnvironmentVariable('VERCEL_REGION') + if (region) { + tags ??= [] + tags.push('vercel.region', region) + } + + return tags +} + +module.exports = { + getVercelPlatformTags, + registerVercelTelemetryRetention, +} diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index ea489e30954..b1ce92bd061 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -14,9 +14,9 @@ const { getServerlessPlatformTags, getServerlessPlatform, enableGCPPubSubPushSubscription, - registerVercelTelemetryRetention, initializeServerlessTelemetry, } = require('../src/serverless') +const { registerVercelTelemetryRetention } = require('../src/serverless/vercel') const Tracer = require('../src/tracer') const { initializeOpenTelemetryLogs } = require('../src/opentelemetry/logs') const { initializeOpenTelemetryMetrics } = require('../src/opentelemetry/metrics') @@ -255,9 +255,9 @@ describe('Vercel telemetry retention', () => { }) it('retains telemetry for an ordinary HTTP Vercel request only once', async () => { - let retained + const retained = [] let flushes = 0 - const context = { waitUntil: promise => { retained = promise } } + const context = { waitUntil: promise => { retained.push(promise) } } globalThis[requestContext] = { get: () => context } const unregister = registerVercelTelemetryRetention({ @@ -269,7 +269,7 @@ describe('Vercel telemetry retention', () => { try { channel('apm:http:server:request:finish').publish({}) channel('apm:next:request:finish').publish({}) - await retained + await Promise.all(retained) assert.strictEqual(flushes, 1) } finally { unregister() From 99a445476c0bab68f7039b92e709082917d602b0 Mon Sep 17 00:00:00 2001 From: William Conti Date: Wed, 12 Aug 2026 22:16:48 -0400 Subject: [PATCH 18/31] docs(otlp): clarify logger flush registration --- packages/dd-trace/src/opentelemetry/logs/index.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index c98773e39ab..7213c79aa21 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -80,9 +80,9 @@ function initializeOpenTelemetryLogs (config) { // Create logger provider with processor for Datadog Agent export const loggerProvider = new LoggerProvider({ processor }) - // Register the logger provider globally with OpenTelemetry API + // Expose this provider to application calls through the OpenTelemetry Logs API. loggerProvider.register() - // Retain only the current global provider when the tracer reinitializes. + // Remove a previous provider callback before replacing it during tracer reinitialization. unregisterTelemetryFlusher?.() unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } From f5c3d826bf01f73466ea0b3553faaf731bfa5a15 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 09:27:41 -0400 Subject: [PATCH 19/31] docs(serverless): clarify telemetry flush registry --- packages/dd-trace/src/flush.js | 6 ++++-- packages/dd-trace/src/opentelemetry/logs/index.js | 3 ++- packages/dd-trace/src/opentelemetry/metrics/index.js | 3 ++- 3 files changed, 8 insertions(+), 4 deletions(-) diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 6fe4a10743d..38e29a5dcaf 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -10,12 +10,14 @@ const log = require('./log') const telemetryFlushers = new Set() /** - * Registers a configured telemetry pipeline for lifecycle flushing. + * Registers a configured telemetry pipeline so serverless lifecycle retention + * waits for its final export alongside trace delivery. * @param {TelemetryFlusher} flusher - * @returns {() => void} Removes the telemetry flusher. + * @returns {() => void} Removes this pipeline when its provider is replaced. */ function registerTelemetryFlusher (flusher) { telemetryFlushers.add(flusher) + // Avoid retaining a replaced provider or flushing it alongside the new one. return () => telemetryFlushers.delete(flusher) } diff --git a/packages/dd-trace/src/opentelemetry/logs/index.js b/packages/dd-trace/src/opentelemetry/logs/index.js index 7213c79aa21..03606c94af9 100644 --- a/packages/dd-trace/src/opentelemetry/logs/index.js +++ b/packages/dd-trace/src/opentelemetry/logs/index.js @@ -82,8 +82,9 @@ function initializeOpenTelemetryLogs (config) { // Expose this provider to application calls through the OpenTelemetry Logs API. loggerProvider.register() - // Remove a previous provider callback before replacing it during tracer reinitialization. + // Remove the old provider callback so lifecycle retention flushes only this global provider. unregisterTelemetryFlusher?.() + // Include final log batches in lifecycle retention with trace delivery. unregisterTelemetryFlusher = registerTelemetryFlusher(done => loggerProvider.forceFlush(done)) } diff --git a/packages/dd-trace/src/opentelemetry/metrics/index.js b/packages/dd-trace/src/opentelemetry/metrics/index.js index 820f2116f77..d90d43050c1 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/index.js +++ b/packages/dd-trace/src/opentelemetry/metrics/index.js @@ -80,8 +80,9 @@ function initializeOpenTelemetryMetrics (config) { const meterProvider = new MeterProvider({ reader }) metrics.setGlobalMeterProvider(meterProvider) - // Retain only the current global provider when the tracer reinitializes. + // Remove the old provider callback so lifecycle retention flushes only this global provider. unregisterTelemetryFlusher?.() + // Include the final metric collection and export in lifecycle retention. unregisterTelemetryFlusher = registerTelemetryFlusher(done => meterProvider.forceFlush(done)) } From 6791765c0b0a3369f3fd9c75afbdc3580898f80e Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 09:31:13 -0400 Subject: [PATCH 20/31] test(otlp): cover multi-batch log flushing --- .../opentelemetry/logs/batch_log_processor.js | 5 ++- .../dd-trace/test/opentelemetry/logs.spec.js | 41 +++++++++++++++++++ 2 files changed, 45 insertions(+), 1 deletion(-) diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 370e7066aa8..4287ffc69cf 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -60,12 +60,15 @@ class BatchLogRecordProcessor { this.#clearTimer() const flushNext = () => { if (this.#logRecords.length === 0) { - // A size-triggered batch can still be in flight after it leaves this queue. + // The queue is empty after a size/timer batch is handed to the exporter, but + // its HTTP request can still be in flight. Join it before lifecycle completion. if (typeof this.exporter.flush === 'function') this.exporter.flush(done) else done?.() return } + // Drain queued records one batch at a time; the final exporter flush joins + // earlier size-triggered batches that are still in flight. const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) this.exporter.export(logRecords, flushNext) } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index f79e25865ae..0752d95c66f 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -162,6 +162,47 @@ describe('OpenTelemetry Logs', () => { sinon.assert.calledOnce(done) }) + it('drains queued batches and waits for earlier size-triggered exports', () => { + const batches = [] + const callbacks = [] + const flushCallbacks = [] + let activeExports = 0 + const completeFlushes = () => { + if (activeExports !== 0) return + while (flushCallbacks.length > 0) flushCallbacks.shift()() + } + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { + batches.push(records) + activeExports++ + callbacks.push(() => { + activeExports-- + done({ code: 0 }) + completeFlushes() + }) + }, + flush: (done) => { + if (activeExports === 0) done() + else flushCallbacks.push(done) + }, + }, 60_000, 2) + const done = sinon.spy() + + for (let index = 0; index < 5; index++) { + processor.onEmit({ body: index }, { name: 'test' }) + } + processor.forceFlush(done) + + assert.deepStrictEqual(batches.map(batch => batch.map(record => record.body)), [ + [0, 1], [2, 3], [4], + ]) + callbacks.shift()() + callbacks.shift()() + callbacks.shift()() + + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] From 94b7729ac69d02b92c44c297c53cb536cd34d88b Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:02:20 -0400 Subject: [PATCH 21/31] refactor(serverless): bound flushing in tracer --- packages/dd-trace/src/flush.js | 22 +++++++++++++++--- packages/dd-trace/src/serverless/vercel.js | 15 +++---------- packages/dd-trace/src/tracer.js | 5 +++-- packages/dd-trace/test/serverless.spec.js | 26 +++++++++------------- packages/dd-trace/test/tracer.spec.js | 21 +++++++++++++++++ 5 files changed, 56 insertions(+), 33 deletions(-) diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index 38e29a5dcaf..ad4482a72f3 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -28,18 +28,34 @@ function registerTelemetryFlusher (flusher) { * _processor?: { _stats?: { forceFlush?: TelemetryFlusher } } * }|undefined} tracer * @param {() => void} [done] + * @param {{ timeout?: number }} [options] */ -function flushAll (tracer, done) { +function flushAll (tracer, done, options) { const traceExporter = tracer?._exporter const traceFlusher = traceExporter?.flush const spanStatsFlusher = tracer?._processor?._stats?.forceFlush let pending = telemetryFlushers.size + (typeof traceFlusher === 'function' ? 1 : 0) + (typeof spanStatsFlusher === 'function' ? 1 : 0) - if (pending === 0) return done?.() + let completed = false + let timeout + const finish = () => { + if (completed) return + completed = true + clearTimeout(timeout) + done?.() + } const complete = () => { - if (--pending === 0) done?.() + if (--pending === 0) finish() + } + + if (pending === 0) return finish() + if (options?.timeout) { + timeout = setTimeout(() => { + log.warn('Timed out waiting for telemetry flush after %dms', options.timeout) + finish() + }, options.timeout) } const flush = flusher => { diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index d0e4c20c1ab..7fc7e2d6854 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -12,7 +12,7 @@ const vercelRetentionHandlers = new WeakMap() const retainedVercelRequests = new WeakMap() /** - * @typedef {{ flushAll?: (done: () => void) => void }} TelemetryFlusher + * @typedef {{ flushAll?: (done: () => void, options?: { timeout?: number }) => void }} TelemetryFlusher */ /** @@ -21,20 +21,11 @@ const retainedVercelRequests = new WeakMap() * @returns {void} */ function flushVercelTelemetry (tracer, done) { - let completed = false - const complete = () => { - if (completed) return - completed = true - clearTimeout(timeout) - done() - } - const timeout = setTimeout(complete, VERCEL_FLUSH_TIMEOUT) - setImmediate(() => { try { - tracer.flushAll(complete) + tracer.flushAll(done, { timeout: VERCEL_FLUSH_TIMEOUT }) } catch { - complete() + done() } }) } diff --git a/packages/dd-trace/src/tracer.js b/packages/dd-trace/src/tracer.js index 608dc5c2778..5f5b473bd2c 100644 --- a/packages/dd-trace/src/tracer.js +++ b/packages/dd-trace/src/tracer.js @@ -154,9 +154,10 @@ class DatadogTracer extends Tracer { /** * Flushes every configured telemetry pipeline. * @param {Function} [done] Called after every configured export completes + * @param {{ timeout?: number }} [options] Bounds this flush operation. */ - flushAll (done) { - flushAll(this, done) + flushAll (done, options) { + flushAll(this, done, options) } scope () { diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index b1ce92bd061..2104f3e59d4 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -276,33 +276,27 @@ describe('Vercel telemetry retention', () => { } }) - it('bounds Vercel retention when an exporter does not complete', async () => { + it('passes Vercel retention timeout to the telemetry flush barrier', async () => { let retained - let timeout - const setTimeoutOriginal = global.setTimeout - const clearTimeoutOriginal = global.clearTimeout - global.setTimeout = (callback, duration) => { - timeout = { callback, duration } - return timeout - } - global.clearTimeout = () => {} + let options globalThis[requestContext] = { get: () => ({ waitUntil: promise => { retained = promise } }), } let unregister try { - unregister = registerVercelTelemetryRetention({ flushAll () {} }) + unregister = registerVercelTelemetryRetention({ + flushAll (done, flushOptions) { + options = flushOptions + done() + }, + }) channel('apm:next:request:finish').publish({}) - await new Promise(resolve => setImmediate(resolve)) - - assert.strictEqual(timeout.duration, 2_000) - timeout.callback() await retained + + assert.deepStrictEqual(options, { timeout: 2_000 }) } finally { unregister?.() - global.setTimeout = setTimeoutOriginal - global.clearTimeout = clearTimeoutOriginal } }) }) diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index d108e3dcf05..7aaed371459 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -69,6 +69,27 @@ describe('Tracer', () => { assert.strictEqual(completed, true) unregister() }) + + it('bounds configured telemetry flushing', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + const timeout = sinon.stub(global, 'setTimeout') + const clearTimeout = sinon.stub(global, 'clearTimeout') + const done = sinon.spy() + const unregister = registerTelemetryFlusher(() => {}) + + try { + flushAll({}, done, { timeout: 2_000 }) + + sinon.assert.calledWith(timeout, sinon.match.func, 2_000) + timeout.firstCall.args[0]() + sinon.assert.calledOnce(done) + sinon.assert.called(clearTimeout) + } finally { + unregister() + timeout.restore() + clearTimeout.restore() + } + }) }) describe('trace', () => { From ab8822326e46e534972a1262a665d633bb78f93d Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:11:37 -0400 Subject: [PATCH 22/31] fix(serverless): retain span stats and bounded log batches --- .../src/exporters/span-stats/index.js | 26 +++++++++++++++++- packages/dd-trace/src/flush.js | 1 + .../opentelemetry/logs/batch_log_processor.js | 27 ++++++++++++------- .../dd-trace/test/opentelemetry/logs.spec.js | 21 +++++++++++++++ 4 files changed, 65 insertions(+), 10 deletions(-) diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index eddfc42bf5f..7d09d8f465b 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -3,6 +3,8 @@ const { Writer } = require('./writer') class SpanStatsExporter { + #activeFlushes = new Set() + constructor (config) { this._url = config.url this._writer = new Writer({ url: this._url }) @@ -10,7 +12,29 @@ class SpanStatsExporter { export (payload, done) { this._writer.append(payload) - this._writer.flush(done) + this.#flush(done) + } + + flush (done = () => {}) { + this.#flush() + + const activeFlushes = [...this.#activeFlushes] + if (activeFlushes.length === 0) return done() + + let pending = activeFlushes.length + const complete = () => { + if (--pending === 0) done() + } + for (const flush of activeFlushes) flush.callbacks.push(complete) + } + + #flush (done) { + const flush = { callbacks: done ? [done] : [] } + this.#activeFlushes.add(flush) + this._writer.flush(() => { + this.#activeFlushes.delete(flush) + for (const callback of flush.callbacks) callback() + }) } } diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index ad4482a72f3..ef961f8d633 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -34,6 +34,7 @@ function flushAll (tracer, done, options) { const traceExporter = tracer?._exporter const traceFlusher = traceExporter?.flush const spanStatsFlusher = tracer?._processor?._stats?.forceFlush + // TODO: Include DSM after DataStreamsProcessor exposes a completion-aware flush API. let pending = telemetryFlushers.size + (typeof traceFlusher === 'function' ? 1 : 0) + (typeof spanStatsFlusher === 'function' ? 1 : 0) diff --git a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js index 4287ffc69cf..67fe227988f 100644 --- a/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js +++ b/packages/dd-trace/src/opentelemetry/logs/batch_log_processor.js @@ -58,19 +58,28 @@ class BatchLogRecordProcessor { */ forceFlush (done) { this.#clearTimer() + // Flush only records present at this boundary. New records belong to the + // later request that produced them and must not extend this lifecycle flush. + const logRecords = this.#logRecords + this.#logRecords = [] + let pending = 2 + const complete = () => { + if (--pending === 0) done?.() + } + + // Join exports already active at this boundary before draining this snapshot. + if (typeof this.exporter.flush === 'function') this.exporter.flush(complete) + else complete() + const flushNext = () => { - if (this.#logRecords.length === 0) { - // The queue is empty after a size/timer batch is handed to the exporter, but - // its HTTP request can still be in flight. Join it before lifecycle completion. - if (typeof this.exporter.flush === 'function') this.exporter.flush(done) - else done?.() + if (logRecords.length === 0) { + complete() return } - // Drain queued records one batch at a time; the final exporter flush joins - // earlier size-triggered batches that are still in flight. - const logRecords = this.#logRecords.splice(0, this.#maxExportBatchSize) - this.exporter.export(logRecords, flushNext) + // Drain the boundary snapshot one batch at a time. + const batch = logRecords.splice(0, this.#maxExportBatchSize) + this.exporter.export(batch, flushNext) } flushNext() } diff --git a/packages/dd-trace/test/opentelemetry/logs.spec.js b/packages/dd-trace/test/opentelemetry/logs.spec.js index 0752d95c66f..2ec004d14b0 100644 --- a/packages/dd-trace/test/opentelemetry/logs.spec.js +++ b/packages/dd-trace/test/opentelemetry/logs.spec.js @@ -203,6 +203,27 @@ describe('OpenTelemetry Logs', () => { sinon.assert.calledOnce(done) }) + it('does not wait for records emitted after the flush boundary', () => { + const exports = [] + let firstExportDone + const processor = new BatchLogRecordProcessor({ + export: (records, done) => { + exports.push(records.map(record => record.body)) + if (records[0].body === 'before') firstExportDone = done + }, + flush: done => done(), + }, 60_000, 2) + const done = sinon.spy() + + processor.onEmit({ body: 'before' }, { name: 'test' }) + processor.forceFlush(done) + processor.onEmit({ body: 'after' }, { name: 'test' }) + firstExportDone({ code: 0 }) + + assert.deepStrictEqual(exports, [['before']]) + sinon.assert.calledOnce(done) + }) + it('exports logs with complete OTLP structure, trace correlation, and instrumentation info', () => { mockOtlpExport((decoded, capturedHeaders) => { const { resource } = decoded.resourceLogs[0] From 54ba4d3edc0750162c3cca94e845b6d0a9867979 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:11:51 -0400 Subject: [PATCH 23/31] test(span-stats): cover in-flight export flush --- .../test/exporters/span-stats/exporter.spec.js | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index 30c431d7e03..4caccdd762f 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -41,6 +41,22 @@ describe('span-stats exporter', () => { sinon.assert.called(writer.flush) }) + it('waits for an in-flight export during flush', () => { + exporter = new Exporter({ url }) + let inFlightDone + writer.flush = sinon.stub() + writer.flush.onFirstCall().callsFake(done => { inFlightDone = done }) + writer.flush.onSecondCall().callsFake(done => done()) + const done = sinon.spy() + + exporter.export('in flight') + exporter.flush(done) + + sinon.assert.notCalled(done) + inFlightDone() + sinon.assert.calledOnce(done) + }) + it('should set url from config', () => { const url = new URL('http://0.0.0.0:1234') From 199cebb66d1999759fa4dfd599bc75ef108a1ca1 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 10:19:13 -0400 Subject: [PATCH 24/31] fix(serverless): wait for Vercel response completion --- packages/dd-trace/src/serverless/vercel.js | 11 +++--- packages/dd-trace/test/serverless.spec.js | 41 ++++++++++++++++------ 2 files changed, 38 insertions(+), 14 deletions(-) diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index 7fc7e2d6854..9b50cab1998 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -4,8 +4,8 @@ const { channel } = require('dc-polyfill') const { getEnvironmentVariable } = require('../config/helper') -const nextRequestFinishChannel = channel('apm:next:request:finish') const httpRequestFinishChannel = channel('apm:http:server:request:finish') +const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') const VERCEL_FLUSH_TIMEOUT = 2_000 const vercelRetentionHandlers = new WeakMap() @@ -44,7 +44,7 @@ function registerVercelRequestFlush (tracer) { if (retainedTracers.has(tracer)) return retainedTracers.add(tracer) - // Retain the invocation synchronously, then flush after Next finishes its root span. + // Retain the invocation synchronously, then flush after the response completes. let done const pending = new Promise(resolve => { done = resolve }) try { @@ -71,12 +71,15 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) - nextRequestFinishChannel.subscribe(flushRequest) + const flushHttp2Response = ({ eventName }) => { + if (eventName === 'finish' || eventName === 'close') flushRequest() + } httpRequestFinishChannel.subscribe(flushRequest) + http2ResponseEmitChannel.subscribe(flushHttp2Response) const unregister = () => { - nextRequestFinishChannel.unsubscribe(flushRequest) httpRequestFinishChannel.unsubscribe(flushRequest) + http2ResponseEmitChannel.unsubscribe(flushHttp2Response) vercelRetentionHandlers.delete(tracer) } vercelRetentionHandlers.set(tracer, unregister) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index 2104f3e59d4..4e47e9e2899 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -213,11 +213,8 @@ describe('Vercel telemetry retention', () => { metrics.getMeter('serverless-flush').createCounter('flush.me').add(1) unregister = registerVercelTelemetryRetention(tracer) - channel('apm:next:request:finish').publish({}) - await Promise.race([ - intakeRequests, - new Promise((_resolve, reject) => setTimeout(() => reject(new Error('Missing intake signals')), 1000)), - ]) + channel('apm:http:server:request:finish').publish({}) + await intakeRequests await retained assert.deepStrictEqual(received, new Set(['traces', 'logs', 'metrics'])) assert.strictEqual(metricPayloads, 2) @@ -229,13 +226,14 @@ describe('Vercel telemetry retention', () => { } }) - it('defers flushing until after Next request finish subscribers return', async () => { + it('waits for HTTP response completion after Next request finish', async () => { process.env.VERCEL = '1' let retained globalThis[requestContext] = { get: () => ({ waitUntil: promise => { retained = promise } }), } - const finishChannel = channel('apm:next:request:finish') + const nextFinishChannel = channel('apm:next:request:finish') + const httpFinishChannel = channel('apm:http:server:request:finish') let finished = false const tracer = { flushAll (done) { @@ -246,8 +244,10 @@ describe('Vercel telemetry retention', () => { const unregister = initializeServerlessTelemetry(tracer) try { - finishChannel.publish({}) + nextFinishChannel.publish({}) + assert.strictEqual(retained, undefined) finished = true + httpFinishChannel.publish({}) await retained } finally { unregister() @@ -268,7 +268,6 @@ describe('Vercel telemetry retention', () => { }) try { channel('apm:http:server:request:finish').publish({}) - channel('apm:next:request:finish').publish({}) await Promise.all(retained) assert.strictEqual(flushes, 1) } finally { @@ -291,7 +290,7 @@ describe('Vercel telemetry retention', () => { done() }, }) - channel('apm:next:request:finish').publish({}) + channel('apm:http:server:request:finish').publish({}) await retained assert.deepStrictEqual(options, { timeout: 2_000 }) @@ -299,4 +298,26 @@ describe('Vercel telemetry retention', () => { unregister?.() } }) + + it('retains telemetry at HTTP/2 response completion', async () => { + let retained + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + + let flushes = 0 + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes++ + done() + }, + }) + try { + channel('apm:http2:server:response:emit').publish({ eventName: 'close' }) + await retained + assert.strictEqual(flushes, 1) + } finally { + unregister() + } + }) }) From e29978393be795a2fcb8ce0ac2c2005614bff837 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 12:36:06 -0400 Subject: [PATCH 25/31] fix(serverless): order Vercel telemetry flushing --- .../src/exporters/span-stats/index.js | 11 ++++------- .../metrics/periodic_metric_reader.js | 13 +++++++++---- .../otlp/otlp_http_exporter_base.js | 1 + packages/dd-trace/src/serverless/vercel.js | 4 ++-- .../test/opentelemetry/metrics.spec.js | 18 ++++++++++++------ packages/dd-trace/test/proxy.spec.js | 19 ------------------- packages/dd-trace/test/serverless.spec.js | 2 ++ 7 files changed, 30 insertions(+), 38 deletions(-) diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 7d09d8f465b..51141be6db2 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -15,17 +15,14 @@ class SpanStatsExporter { this.#flush(done) } - flush (done = () => {}) { - this.#flush() - + flush (done) { const activeFlushes = [...this.#activeFlushes] - if (activeFlushes.length === 0) return done() - - let pending = activeFlushes.length + let pending = activeFlushes.length + 1 const complete = () => { - if (--pending === 0) done() + if (--pending === 0) done?.() } for (const flush of activeFlushes) flush.callbacks.push(complete) + this.#flush(complete) } #flush (done) { diff --git a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js index fbf4cab33c9..32de8d9ae99 100644 --- a/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js +++ b/packages/dd-trace/src/opentelemetry/metrics/periodic_metric_reader.js @@ -205,10 +205,15 @@ class PeriodicMetricReader { done?.() return } - this.#collectAndExport(() => { - if (typeof this.exporter.flush === 'function') this.exporter.flush(done) - else done?.() - }) + let pending = 2 + const complete = () => { + if (--pending === 0) done?.() + } + + // Snapshot requests already active before starting this flush's export. + if (typeof this.exporter.flush === 'function') this.exporter.flush(complete) + else complete() + this.#collectAndExport(complete) } /** diff --git a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js index 7b90bff8746..d9bba361ad8 100644 --- a/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js +++ b/packages/dd-trace/src/opentelemetry/otlp/otlp_http_exporter_base.js @@ -139,6 +139,7 @@ class OtlpHttpExporterBase { req.end() }) } catch (error) { + log.error('Error sending OTLP %s:', this.signalType, error) complete({ code: 1, error }) } } diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index 9b50cab1998..bcadd1ca127 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -7,7 +7,7 @@ const { getEnvironmentVariable } = require('../config/helper') const httpRequestFinishChannel = channel('apm:http:server:request:finish') const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') -const VERCEL_FLUSH_TIMEOUT = 2_000 +const VERCEL_FLUSH_TIMEOUT = 2000 const vercelRetentionHandlers = new WeakMap() const retainedVercelRequests = new WeakMap() @@ -72,7 +72,7 @@ function registerVercelTelemetryRetention (tracer) { if (typeof tracer?.flushAll !== 'function') return const flushRequest = () => registerVercelRequestFlush(tracer) const flushHttp2Response = ({ eventName }) => { - if (eventName === 'finish' || eventName === 'close') flushRequest() + if (eventName === 'close') flushRequest() } httpRequestFinishChannel.subscribe(flushRequest) http2ResponseEmitChannel.subscribe(flushHttp2Response) diff --git a/packages/dd-trace/test/opentelemetry/metrics.spec.js b/packages/dd-trace/test/opentelemetry/metrics.spec.js index 3d55684b41c..4f12bba0004 100644 --- a/packages/dd-trace/test/opentelemetry/metrics.spec.js +++ b/packages/dd-trace/test/opentelemetry/metrics.spec.js @@ -664,23 +664,29 @@ describe('OpenTelemetry Meter Provider', () => { describe('Lifecycle', () => { it('waits for an in-flight export during forceFlush', () => { - let exportDone - let flushDone + const exports = [] + const flushes = [] const reader = new PeriodicMetricReader({ - export: (metrics, done) => { exportDone = done }, - flush: (done) => { flushDone = done }, + export: (metrics, done) => { exports.push(done) }, + flush: (done) => { flushes.push(done) }, }, 60_000, 'DELTA', 1024) const meter = new MeterProvider({ reader }).getMeter('test') + const firstDone = sinon.spy() const done = sinon.spy() meter.createCounter('in-flight').add(1) + reader.forceFlush(firstDone) + flushes.shift()() + meter.createCounter('boundary').add(1) reader.forceFlush(done) sinon.assert.notCalled(done) - exportDone({ code: 0 }) + assert.strictEqual(exports.length, 2) + exports[1]({ code: 0 }) sinon.assert.notCalled(done) - flushDone() + flushes[0]() sinon.assert.calledOnce(done) + exports[0]({ code: 0 }) reader.shutdown() }) diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index b48cb7d06cb..0dfc64e1e3b 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -274,25 +274,6 @@ describe('TracerProxy', () => { }, }) - const { enable: openfeatureRcEnable } = require('../src/openfeature/remote_config') - const noopOpenfeature = {} - - featureRegistry.registerFeature({ - name: 'openfeature', - noop: noopOpenfeature, - factory: () => openfeature, - provider: () => OpenFeatureProvider, - /** @param {object} config */ - isEnabled (config) { - return config.featureFlags.DD_FEATURE_FLAGS_ENABLED - }, - remoteConfig (rc, config, proxy) { - const subscribe = config.featureFlags.DD_FEATURE_FLAGS_ENABLED && - config.featureFlags.DD_FEATURE_FLAGS_CONFIGURATION_SOURCE === 'remote_config' - openfeatureRcEnable(rc, () => proxy.openfeature, subscribe) - }, - }) - proxy = new ProxyClass() }) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index 4e47e9e2899..f2f989bea91 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -313,6 +313,8 @@ describe('Vercel telemetry retention', () => { }, }) try { + channel('apm:http2:server:response:emit').publish({ eventName: 'finish' }) + assert.strictEqual(retained, undefined) channel('apm:http2:server:response:emit').publish({ eventName: 'close' }) await retained assert.strictEqual(flushes, 1) From 3ff70e5c9744ef498b013a9dc5d74d2acc9702f2 Mon Sep 17 00:00:00 2001 From: William Conti Date: Thu, 13 Aug 2026 12:50:30 -0400 Subject: [PATCH 26/31] fix(exporters): clean up failed flush records --- packages/dd-trace/src/exporters/agent/index.js | 10 ++++++++-- packages/dd-trace/src/exporters/span-stats/index.js | 10 ++++++++-- .../dd-trace/test/exporters/agent/exporter.spec.js | 13 +++++++++++++ .../test/exporters/span-stats/exporter.spec.js | 13 +++++++++++++ 4 files changed, 42 insertions(+), 4 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index b69706fc12e..744080acc93 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -73,10 +73,16 @@ class AgentExporter { #flush () { const flush = { callbacks: [] } this.#activeFlushes.add(flush) - this._writer.flush(() => { + const complete = () => { this.#activeFlushes.delete(flush) for (const callback of flush.callbacks) callback() - }) + } + try { + this._writer.flush(complete) + } catch (error) { + complete() + throw error + } } } diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 51141be6db2..ca099441ac6 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -28,10 +28,16 @@ class SpanStatsExporter { #flush (done) { const flush = { callbacks: done ? [done] : [] } this.#activeFlushes.add(flush) - this._writer.flush(() => { + const complete = () => { this.#activeFlushes.delete(flush) for (const callback of flush.callbacks) callback() - }) + } + try { + this._writer.flush(complete) + } catch (error) { + complete() + throw error + } } } diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index 1509bc7050a..40bc80d83e3 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -127,6 +127,19 @@ describe('Exporter', () => { callbacks[0]() sinon.assert.calledOnce(flushed) }) + + it('does not retain a failed writer flush', () => { + writer.flush = sinon.stub() + writer.flush.onFirstCall().throws(new Error('encode failed')) + writer.flush.onSecondCall().callsFake(done => done()) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + assert.throws(() => exporter.export([span]), /encode failed/) + exporter.flush(flushed) + + sinon.assert.calledOnce(flushed) + }) }) describe('setUrl', () => { diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index 4caccdd762f..635e4d816f8 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -57,6 +57,19 @@ describe('span-stats exporter', () => { sinon.assert.calledOnce(done) }) + it('does not retain a failed writer flush', () => { + writer.flush = sinon.stub() + writer.flush.onFirstCall().throws(new Error('encode failed')) + writer.flush.onSecondCall().callsFake(done => done()) + exporter = new Exporter({ url }) + const done = sinon.spy() + + assert.throws(() => exporter.export('failed export'), /encode failed/) + exporter.flush(done) + + sinon.assert.calledOnce(done) + }) + it('should set url from config', () => { const url = new URL('http://0.0.0.0:1234') From 614e2b16fd4a2d4ba2f6e4966903d4cec4e94da8 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 11:26:50 -0400 Subject: [PATCH 27/31] fix(serverless): retain outer Vercel telemetry --- packages/dd-trace/src/serverless/vercel.js | 8 ------- packages/dd-trace/src/span_stats.js | 6 ++++- packages/dd-trace/test/serverless.spec.js | 28 ++++++++++++++++++++++ packages/dd-trace/test/span_stats.spec.js | 27 ++++++++++++++++++++- 4 files changed, 59 insertions(+), 10 deletions(-) diff --git a/packages/dd-trace/src/serverless/vercel.js b/packages/dd-trace/src/serverless/vercel.js index bcadd1ca127..eb65fcb0bf3 100644 --- a/packages/dd-trace/src/serverless/vercel.js +++ b/packages/dd-trace/src/serverless/vercel.js @@ -9,7 +9,6 @@ const http2ResponseEmitChannel = channel('apm:http2:server:response:emit') const VERCEL_REQUEST_CONTEXT = Symbol.for('@vercel/request-context') const VERCEL_FLUSH_TIMEOUT = 2000 const vercelRetentionHandlers = new WeakMap() -const retainedVercelRequests = new WeakMap() /** * @typedef {{ flushAll?: (done: () => void, options?: { timeout?: number }) => void }} TelemetryFlusher @@ -36,13 +35,6 @@ function registerVercelRequestFlush (tracer) { const { waitUntil } = requestContext if (typeof waitUntil !== 'function') return - let retainedTracers = retainedVercelRequests.get(requestContext) - if (!retainedTracers) { - retainedTracers = new WeakSet() - retainedVercelRequests.set(requestContext, retainedTracers) - } - if (retainedTracers.has(tracer)) return - retainedTracers.add(tracer) // Retain the invocation synchronously, then flush after the response completes. let done diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index d35d3798fa8..340e86980e3 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -260,7 +260,11 @@ class SpanStatsProcessor { RuntimeID: this.tags['runtime-id'], Sequence: ++this.sequence, ProcessTags: processTags.serialized, - }, done) + }) + // `export` can overlap an interval export. Use the exporter's barrier so + // this lifecycle flush waits for both that existing request and this + // boundary payload before Vercel releases the invocation. + if (done) this.exporter.flush(done) } else if (this.otlpExporter && drained.length > 0) { this.otlpExporter.export(drained, this.bucketSizeNs, () => { if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index f2f989bea91..89d36b942fe 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -275,6 +275,34 @@ describe('Vercel telemetry retention', () => { } }) + it('retains telemetry again when an outer Vercel response follows a nested request', async () => { + const retained = [] + const flushes = [] + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained.push(promise) } }), + } + const unregister = registerVercelTelemetryRetention({ + flushAll (done) { + flushes.push(done) + }, + }) + try { + channel('apm:http:server:request:finish').publish({ req: {} }) + await new Promise(resolve => setImmediate(resolve)) + channel('apm:http:server:request:finish').publish({ req: {} }) + await new Promise(resolve => setImmediate(resolve)) + + // Other tracers initialized by this file can share this request context; + // the callback count below isolates this test's tracer. + assert.ok(retained.length >= 2) + assert.strictEqual(flushes.length, 2) + flushes[0]() + flushes[1]() + } finally { + unregister() + } + }) + it('passes Vercel retention timeout to the telemetry flush barrier', async () => { let retained let options diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index 8ff17ca97fa..b472b1c5789 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -81,6 +81,7 @@ const syntheticSpan = { const exporter = { export: sinon.stub(), + flush: sinon.stub(), } const SpanStatsExporter = sinon.stub().returns(exporter) @@ -664,7 +665,9 @@ describe('SpanStatsProcessor', () => { it('force flushes pending agent span statistics', () => { exporter.export.resetHistory() - exporter.export.callsFake((_payload, done) => done()) + exporter.flush.resetHistory() + exporter.export.callsFake(() => {}) + exporter.flush.callsFake(done => done()) const p = new SpanStatsProcessor(config) clearTimeout(p.timer) p.onSpanFinished(topLevelSpan) @@ -673,9 +676,31 @@ describe('SpanStatsProcessor', () => { p.forceFlush(() => { flushed = true }) assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) assert.ok(flushed) assert.strictEqual(p.buckets.size, 0) exporter.export.resetBehavior() + exporter.flush.resetBehavior() + }) + + it('joins an in-flight agent span statistics export during force flush', () => { + exporter.export.resetHistory() + exporter.flush.resetHistory() + const p = new SpanStatsProcessor(config) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + + let flushDone + exporter.flush.callsFake(done => { flushDone = done }) + let flushed = false + p.forceFlush(() => { flushed = true }) + + assert.ok(exporter.export.calledOnce) + assert.ok(exporter.flush.calledOnce) + assert.strictEqual(flushed, false) + flushDone() + assert.strictEqual(flushed, true) + exporter.flush.resetBehavior() }) it('should record spans when only OTLP is enabled', () => { From 98cf0f901e5105319fc9105ed5a44ed63f392891 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 11:46:17 -0400 Subject: [PATCH 28/31] fix(exporters): retain in-flight traces after flush failure --- packages/dd-trace/src/exporters/agent/index.js | 11 +++++++++-- .../test/exporters/agent/exporter.spec.js | 16 ++++++++++++++++ 2 files changed, 25 insertions(+), 2 deletions(-) diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index 744080acc93..9019120d530 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -58,9 +58,16 @@ class AgentExporter { flush (done = () => {}) { clearTimeout(this.#timer) this.#timer = undefined - this.#flush() - const activeFlushes = [...this.#activeFlushes] + // Snapshot before the boundary flush so a failed encoding cannot cause a + // Vercel lifecycle flush to abandon exports that were already in flight. + let activeFlushes = [...this.#activeFlushes] + try { + this.#flush() + } catch (error) { + log.error('Failed to flush traces: %s', error.message) + } + activeFlushes = [...new Set([...activeFlushes, ...this.#activeFlushes])] if (activeFlushes.length === 0) return done() let pending = activeFlushes.length diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index 40bc80d83e3..b699220d8a3 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -140,6 +140,22 @@ describe('Exporter', () => { sinon.assert.calledOnce(flushed) }) + + it('waits for an earlier export when the boundary flush fails', () => { + let inFlightDone + writer.flush = sinon.stub() + writer.flush.onFirstCall().callsFake(done => { inFlightDone = done }) + writer.flush.onSecondCall().throws(new Error('encode failed')) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + exporter.export([span]) + exporter.flush(flushed) + + sinon.assert.notCalled(flushed) + inFlightDone() + sinon.assert.calledOnce(flushed) + }) }) describe('setUrl', () => { From 5a7fa9083059f91f2c12a194b6e95a4eafdede1b Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 13:46:22 -0400 Subject: [PATCH 29/31] fix(serverless): retain runtime metrics and span stats --- packages/dd-trace/src/dogstatsd.js | 42 +++++++++++------ .../src/exporters/span-stats/index.js | 17 ++++++- packages/dd-trace/src/proxy.js | 6 +++ .../dd-trace/src/runtime_metrics/index.js | 5 +++ .../runtime_metrics/otlp_runtime_metrics.js | 5 +++ .../src/runtime_metrics/runtime_metrics.js | 23 +++++++--- packages/dd-trace/src/span_stats.js | 6 +-- packages/dd-trace/test/dogstatsd.spec.js | 45 +++++++++++++++++-- .../exporters/span-stats/exporter.spec.js | 16 +++++++ packages/dd-trace/test/proxy.spec.js | 15 +++++++ .../dd-trace/test/runtime_metrics.spec.js | 32 ++++++++++++- packages/dd-trace/test/span_stats.spec.js | 12 +++-- 12 files changed, 186 insertions(+), 38 deletions(-) diff --git a/packages/dd-trace/src/dogstatsd.js b/packages/dd-trace/src/dogstatsd.js index 19a580ad2db..0c2b1a53759 100644 --- a/packages/dd-trace/src/dogstatsd.js +++ b/packages/dd-trace/src/dogstatsd.js @@ -67,23 +67,23 @@ class DogStatsDClient { this._add(stat, value, TYPE_HISTOGRAM, tags) } - flush () { + flush (done) { const queue = this._enqueue() - if (queue.length === 0) return + if (queue.length === 0) return done?.() log.debug('Flushing %s metrics via %s', queue.length, this._httpOptions ? 'HTTP' : 'UDP') this._queue = [] if (this._httpOptions) { - this._sendHttp(queue) + this._sendHttp(queue, done) } else { - this._sendUdp(queue) + this._sendUdp(queue, done) } } - _sendHttp (queue) { + _sendHttp (queue, done) { const buffer = Buffer.concat(queue) request(buffer, this._httpOptions, (err) => { if (err) { @@ -95,32 +95,46 @@ class DogStatsDClient { // options. Either way, we can give UDP a try. this._httpOptions = undefined } - this._sendUdp(queue) + this._sendUdp(queue, done) + } else { + done?.() } }) } - _sendUdp (queue) { + _sendUdp (queue, done) { // dgram resolves the local address via the instrumented dns.lookup when it // binds on first send; the noop store keeps that self-traffic off the trace. legacyStorage.run({ noop: true }, () => { if (this._family === 0) { this.#lookup(this._host, (error, address, family) => { - if (error) return log.error('DogStatsDClient: Host not found', error) - this._sendUdpFromQueue(queue, address, family) + if (error) { + log.error('DogStatsDClient: Host not found', error) + return done?.() + } + this._sendUdpFromQueue(queue, address, family, done) }) } else { - this._sendUdpFromQueue(queue, this._host, this._family) + this._sendUdpFromQueue(queue, this._host, this._family, done) } }) } - _sendUdpFromQueue (queue, address, family) { + _sendUdpFromQueue (queue, address, family, done) { const socket = family === 6 ? this._udp6 : this._udp4 + let pending = queue.length + const complete = () => { + if (--pending === 0) done?.() + } for (const buffer of queue) { log.debug('Sending to DogStatsD: %s', buffer) - socket.send(buffer, 0, buffer.length, this._port, address) + try { + socket.send(buffer, 0, buffer.length, this._port, address, complete) + } catch (error) { + log.error('DogStatsDClient: UDP error sending metrics', error) + complete() + } } } @@ -212,12 +226,12 @@ class MetricsAggregationClient { this.reset() } - flush () { + flush (done) { this._captureCounters() this._captureGauges() this._captureHistograms() - this._client.flush() + this._client.flush(done) } reset () { diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index ca099441ac6..b3acca1ec41 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -11,8 +11,23 @@ class SpanStatsExporter { } export (payload, done) { + if (done) { + const activeFlushes = [...this.#activeFlushes] + let pending = activeFlushes.length + 1 + const complete = () => { + if (--pending === 0) done() + } + for (const flush of activeFlushes) flush.callbacks.push(complete) + this._writer.append(payload) + try { + this.#flush(complete) + } catch { + // `#flush` has notified the boundary request; keep waiting for prior exports. + } + return + } this._writer.append(payload) - this.#flush(done) + this.#flush() } flush (done) { diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 30cb399c6bf..455919ec654 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -13,6 +13,7 @@ const nomenclature = require('./service-naming') const PluginManager = require('./plugin_manager') const NoopDogStatsDClient = require('./noop/dogstatsd') const { IS_SERVERLESS, initializeServerlessTelemetry } = require('./serverless') +const { registerTelemetryFlusher } = require('./flush') const processTags = require('./process-tags') const { isTrue } = require('./util') const { @@ -41,6 +42,8 @@ const OPENFEATURE_STATE_NOOP = 0 const OPENFEATURE_STATE_LAZY = 1 const OPENFEATURE_STATE_ACTIVE = 2 +let unregisterRuntimeMetricsFlusher + class LazyModule { constructor (provider) { this.provider = provider @@ -253,8 +256,11 @@ class Tracer extends NoopProxy { initializeOpenTelemetryMetrics(config) } + unregisterRuntimeMetricsFlusher?.() + unregisterRuntimeMetricsFlusher = undefined if (config.runtimeMetrics.enabled) { runtimeMetrics.start(config) + unregisterRuntimeMetricsFlusher = registerTelemetryFlusher(done => runtimeMetrics.flush(done)) } this.#updateTracing(config) diff --git a/packages/dd-trace/src/runtime_metrics/index.js b/packages/dd-trace/src/runtime_metrics/index.js index f9451beb359..600132de8e7 100644 --- a/packages/dd-trace/src/runtime_metrics/index.js +++ b/packages/dd-trace/src/runtime_metrics/index.js @@ -13,6 +13,7 @@ const noop = runtimeMetrics = { gauge () {}, increment () {}, decrement () {}, + flush (done) { done?.() }, } module.exports = { @@ -42,6 +43,10 @@ module.exports = { runtimeMetrics = noop Object.setPrototypeOf(module.exports, noop) }, + + flush (done) { + runtimeMetrics.flush(done) + }, } Object.setPrototypeOf(module.exports, noop) diff --git a/packages/dd-trace/src/runtime_metrics/otlp_runtime_metrics.js b/packages/dd-trace/src/runtime_metrics/otlp_runtime_metrics.js index fbb6e1d7675..3c9ec42c45b 100644 --- a/packages/dd-trace/src/runtime_metrics/otlp_runtime_metrics.js +++ b/packages/dd-trace/src/runtime_metrics/otlp_runtime_metrics.js @@ -245,6 +245,11 @@ module.exports = { decrement (name, tag) { this.count(name, -1, tag) }, + + flush (done) { + if (client) return client.flush(done) + done?.() + }, } /** diff --git a/packages/dd-trace/src/runtime_metrics/runtime_metrics.js b/packages/dd-trace/src/runtime_metrics/runtime_metrics.js index 74e522b047d..1f7d0a431c0 100644 --- a/packages/dd-trace/src/runtime_metrics/runtime_metrics.js +++ b/packages/dd-trace/src/runtime_metrics/runtime_metrics.js @@ -27,6 +27,7 @@ let client = null let lastTime = 0 let lastCpuUsage = null let eventLoopDelayObserver = null +let capture = null // !!!!!!!!!!! // IMPORTANT @@ -76,11 +77,10 @@ module.exports = { lastTime = performance.now() if (nativeMetrics) { - interval = setInterval(() => { + capture = () => { captureNativeMetrics(trackEventLoop, trackGc) captureCommonMetrics(trackEventLoop) - client.flush() - }, flushIntervalMs) + } } else { lastCpuUsage = process.cpuUsage() @@ -92,17 +92,21 @@ module.exports = { eventLoopDelayObserver.enable() } - interval = setInterval(() => { + capture = () => { captureCpuUsage() captureCommonMetrics(trackEventLoop) captureHeapSpace() if (trackEventLoop) { captureEventLoopDelay() } - client.flush() - }, flushIntervalMs) + } } + interval = setInterval(() => { + capture() + client.flush() + }, flushIntervalMs) + interval.unref?.() }, @@ -114,6 +118,7 @@ module.exports = { interval = null client = null + capture = null lastCpuUsage = null gcObserver?.disconnect() @@ -158,6 +163,12 @@ module.exports = { decrement (name, tag) { this.count(name, -1, tag) }, + + flush (done) { + if (!client) return done?.() + capture?.() + client.flush(done) + }, } function captureCpuUsage () { diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index 340e86980e3..d35d3798fa8 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -260,11 +260,7 @@ class SpanStatsProcessor { RuntimeID: this.tags['runtime-id'], Sequence: ++this.sequence, ProcessTags: processTags.serialized, - }) - // `export` can overlap an interval export. Use the exporter's barrier so - // this lifecycle flush waits for both that existing request and this - // boundary payload before Vercel releases the invocation. - if (done) this.exporter.flush(done) + }, done) } else if (this.otlpExporter && drained.length > 0) { this.otlpExporter.export(drained, this.bucketSizeNs, () => { if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) diff --git a/packages/dd-trace/test/dogstatsd.spec.js b/packages/dd-trace/test/dogstatsd.spec.js index 2544531201b..1c30b47d92d 100644 --- a/packages/dd-trace/test/dogstatsd.spec.js +++ b/packages/dd-trace/test/dogstatsd.spec.js @@ -237,6 +237,17 @@ describe('dogstatsd', () => { sinon.assert.notCalled(log.debug) }) + it('calls the flush callback after UDP accepts the metrics', (done) => { + udp4.send = sinon.stub().callsFake((...args) => args.at(-1)()) + client = createDogStatsDClient() + + client.gauge('test.avg', 1) + client.flush(() => { + sinon.assert.calledOnce(udp4.send) + done() + }) + }) + it('logs the metric count and the UDP transport on a non-empty flush', () => { client = createDogStatsDClient() @@ -388,6 +399,22 @@ describe('dogstatsd', () => { client.flush() }) + it('calls the flush callback after the HTTP proxy responds', (done) => { + client = createDogStatsDClient({ + metricsProxyUrl: `http://localhost:${httpPort}`, + }) + + client.gauge('test.avg', 1) + client.flush(() => { + try { + assert.strictEqual(Buffer.concat(httpData).toString(), 'test.avg:1|g\n') + done() + } catch (error) { + done(error) + } + }) + }) + it('should support HTTP via URL object', (done) => { assertData = () => { try { @@ -444,13 +471,23 @@ describe('dogstatsd', () => { } }) - statusCode = null + const request = sinon.stub().callsFake((buffer, options, callback) => { + callback(new Error('connection refused')) + }) + const { DogStatsDClient: FailingDogStatsDClient } = proxyquire.noPreserveCache().noCallThru()('../src/dogstatsd', { + dgram, + '../../datadog-core': datadogCore, + './exporters/common/docker': docker, + './exporters/common/request': request, + './log': log, + }) - // host exists but port does not, ECONNREFUSED - client = createDogStatsDClient({ - metricsProxyUrl: 'http://localhost:32700', + client = new FailingDogStatsDClient({ host: 'localhost', + lookup: dns.lookup, + metricsProxyUrl: 'http://localhost:8126', port: 8125, + tags: [], }) client.increment('test.foo', 10) diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index 635e4d816f8..f34efcbd994 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -70,6 +70,22 @@ describe('span-stats exporter', () => { sinon.assert.calledOnce(done) }) + it('waits for an in-flight export when the boundary flush fails', () => { + writer.flush = sinon.stub() + let inFlightDone + writer.flush.onFirstCall().callsFake(done => { inFlightDone = done }) + writer.flush.onSecondCall().throws(new Error('encode failed')) + exporter = new Exporter({ url }) + const done = sinon.spy() + + exporter.export('in flight') + exporter.export('failed boundary', done) + + sinon.assert.notCalled(done) + inFlightDone() + sinon.assert.calledOnce(done) + }) + it('should set url from config', () => { const url = new URL('http://0.0.0.0:1234') diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index 0dfc64e1e3b..f835a1c0fc1 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -47,6 +47,7 @@ describe('TracerProxy', () => { let NoopDogStatsDClient let OpenFeatureProvider let openfeatureProvider + let registerTelemetryFlusher beforeEach(() => { process.env.DD_TRACE_MOCHA_ENABLED = 'false' @@ -180,8 +181,11 @@ describe('TracerProxy', () => { runtimeMetrics = { start: sinon.spy(), + flush: sinon.spy(), } + registerTelemetryFlusher = sinon.stub().returns(() => {}) + profiler = { start: sinon.spy(), } @@ -272,6 +276,7 @@ describe('TracerProxy', () => { './serverless': { IS_SERVERLESS: false, }, + './flush': { registerTelemetryFlusher }, }) proxy = new ProxyClass() @@ -589,6 +594,16 @@ describe('TracerProxy', () => { sinon.assert.called(runtimeMetrics.start) }) + it('registers the runtime metrics flush with the serverless lifecycle', () => { + config.runtimeMetrics.enabled = true + const done = sinon.spy() + + proxy.init() + registerTelemetryFlusher.firstCall.args[0](done) + + sinon.assert.calledOnceWithExactly(runtimeMetrics.flush, done) + }) + it('should expose noop metrics methods prior to initialization', () => { proxy.dogstatsd.increment('foo') }) diff --git a/packages/dd-trace/test/runtime_metrics.spec.js b/packages/dd-trace/test/runtime_metrics.spec.js index 94309d1d4e5..25317b18285 100644 --- a/packages/dd-trace/test/runtime_metrics.spec.js +++ b/packages/dd-trace/test/runtime_metrics.spec.js @@ -74,6 +74,7 @@ NATIVE_METRICS_VARIANTS.forEach((nativeMetrics) => { gauge () {}, increment () {}, decrement () {}, + flush (done) { done?.() }, }) proxy = proxyquire('../src/runtime_metrics', { @@ -152,6 +153,20 @@ NATIVE_METRICS_VARIANTS.forEach((nativeMetrics) => { sinon.assert.notCalled(runtimeMetrics.decrement) sinon.assert.calledOnce(runtimeMetrics.stop) }) + + it('flushes when enabled and is noop when disabled', () => { + const done = sinon.spy() + + proxy.start() + proxy.flush(done) + sinon.assert.notCalled(runtimeMetrics.flush) + sinon.assert.calledOnce(done) + + config.runtimeMetrics.enabled = true + proxy.start(config) + proxy.flush(done) + sinon.assert.calledOnceWithExactly(runtimeMetrics.flush, done) + }) }) describe('runtimeMetrics', () => { @@ -186,7 +201,7 @@ NATIVE_METRICS_VARIANTS.forEach((nativeMetrics) => { gauge: sinon.spy(), increment: sinon.spy(), histogram: sinon.spy(), - flush: sinon.spy(), + flush: sinon.stub().callsFake(done => done?.()), } const proxiedObject = { @@ -246,6 +261,21 @@ NATIVE_METRICS_VARIANTS.forEach((nativeMetrics) => { runtimeMetrics.stop() }) + it('captures and waits for the final runtime metrics flush', (done) => { + client.flush.resetHistory() + client.gauge.resetHistory() + + runtimeMetrics.flush(() => { + try { + sinon.assert.calledOnce(client.flush) + sinon.assert.called(client.gauge) + done() + } catch (error) { + done(error) + } + }) + }) + describe('start', () => { it('it should initialize the Dogstatsd client with the correct options', function () { runtimeMetrics.stop() diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index b472b1c5789..0e8b50e76de 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -666,8 +666,7 @@ describe('SpanStatsProcessor', () => { it('force flushes pending agent span statistics', () => { exporter.export.resetHistory() exporter.flush.resetHistory() - exporter.export.callsFake(() => {}) - exporter.flush.callsFake(done => done()) + exporter.export.callsFake((_payload, done) => done()) const p = new SpanStatsProcessor(config) clearTimeout(p.timer) p.onSpanFinished(topLevelSpan) @@ -676,11 +675,10 @@ describe('SpanStatsProcessor', () => { p.forceFlush(() => { flushed = true }) assert.ok(exporter.export.calledOnce) - assert.ok(exporter.flush.calledOnce) + assert.ok(exporter.flush.notCalled) assert.ok(flushed) assert.strictEqual(p.buckets.size, 0) exporter.export.resetBehavior() - exporter.flush.resetBehavior() }) it('joins an in-flight agent span statistics export during force flush', () => { @@ -691,16 +689,16 @@ describe('SpanStatsProcessor', () => { p.onSpanFinished(topLevelSpan) let flushDone - exporter.flush.callsFake(done => { flushDone = done }) + exporter.export.callsFake((_payload, done) => { flushDone = done }) let flushed = false p.forceFlush(() => { flushed = true }) assert.ok(exporter.export.calledOnce) - assert.ok(exporter.flush.calledOnce) + assert.ok(exporter.flush.notCalled) assert.strictEqual(flushed, false) flushDone() assert.strictEqual(flushed, true) - exporter.flush.resetBehavior() + exporter.export.resetBehavior() }) it('should record spans when only OTLP is enabled', () => { From 859506db872ddab11933ffafb2a295d35cb09071 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 14:55:36 -0400 Subject: [PATCH 30/31] fix(serverless): retain all Vercel telemetry flushes --- packages/dd-trace/src/dogstatsd.js | 28 +++++++++++++-- .../dd-trace/src/exporters/agent/index.js | 23 ++++++++++-- .../dd-trace/src/exporters/agent/writer.js | 10 +++++- .../src/exporters/span-stats/index.js | 4 ++- packages/dd-trace/src/proxy.js | 10 ++++-- packages/dd-trace/test/dogstatsd.spec.js | 22 ++++++++++++ .../test/exporters/agent/exporter.spec.js | 24 ++++++++++++- .../test/exporters/agent/writer.spec.js | 14 ++++++++ .../exporters/span-stats/exporter.spec.js | 4 +++ packages/dd-trace/test/proxy.spec.js | 20 ++++++++++- packages/dd-trace/test/serverless.spec.js | 35 +++++++++++++++++++ packages/dd-trace/test/tracer.spec.js | 13 +++++++ 12 files changed, 195 insertions(+), 12 deletions(-) diff --git a/packages/dd-trace/src/dogstatsd.js b/packages/dd-trace/src/dogstatsd.js index 0c2b1a53759..495210d2262 100644 --- a/packages/dd-trace/src/dogstatsd.js +++ b/packages/dd-trace/src/dogstatsd.js @@ -41,6 +41,7 @@ class DogStatsDClient { this._tags = options.tags this.#tagsPrefix = this._tags?.length ? `|#${this._tags.join(',')}` : '' this._queue = [] + this._activeFlushes = new Set() this._buffer = '' this._offset = 0 this._udp4 = this._socket('udp4') @@ -69,20 +70,41 @@ class DogStatsDClient { flush (done) { const queue = this._enqueue() + const activeFlushes = [...this._activeFlushes] - if (queue.length === 0) return done?.() + if (queue.length === 0) return this._joinFlushes(activeFlushes, done) log.debug('Flushing %s metrics via %s', queue.length, this._httpOptions ? 'HTTP' : 'UDP') this._queue = [] + const flush = { callbacks: [] } + this._activeFlushes.add(flush) + activeFlushes.push(flush) + this._joinFlushes(activeFlushes, done) + if (this._httpOptions) { - this._sendHttp(queue, done) + this._sendHttp(queue, () => this._completeFlush(flush)) } else { - this._sendUdp(queue, done) + this._sendUdp(queue, () => this._completeFlush(flush)) } } + _joinFlushes (flushes, done) { + if (!done) return + let pending = flushes.length + if (pending === 0) return done() + const complete = () => { + if (--pending === 0) done() + } + for (const flush of flushes) flush.callbacks.push(complete) + } + + _completeFlush (flush) { + this._activeFlushes.delete(flush) + for (const done of flush.callbacks) done() + } + _sendHttp (queue, done) { const buffer = Buffer.concat(queue) request(buffer, this._httpOptions, (err) => { diff --git a/packages/dd-trace/src/exporters/agent/index.js b/packages/dd-trace/src/exporters/agent/index.js index 9019120d530..695cd846ae4 100644 --- a/packages/dd-trace/src/exporters/agent/index.js +++ b/packages/dd-trace/src/exporters/agent/index.js @@ -24,6 +24,7 @@ class AgentExporter { lookup, protocolVersion, headers, + onFlush: this.#trackWriterFlush.bind(this), }) globalThis[Symbol.for('dd-trace')].beforeExitHandlers.add(this.flush.bind(this)) @@ -77,15 +78,31 @@ class AgentExporter { for (const flush of activeFlushes) flush.callbacks.push(complete) } - #flush () { - const flush = { callbacks: [] } + #flush (done) { + const flush = { callbacks: done ? [done] : [] } this.#activeFlushes.add(flush) const complete = () => { this.#activeFlushes.delete(flush) for (const callback of flush.callbacks) callback() } try { - this._writer.flush(complete) + const flush = this._writer.flushDirect ?? this._writer.flush + flush.call(this._writer, complete) + } catch (error) { + complete() + throw error + } + } + + #trackWriterFlush (flush, done) { + const activeFlush = { callbacks: done ? [done] : [] } + this.#activeFlushes.add(activeFlush) + const complete = () => { + this.#activeFlushes.delete(activeFlush) + for (const callback of activeFlush.callbacks) callback() + } + try { + flush(complete) } catch (error) { complete() throw error diff --git a/packages/dd-trace/src/exporters/agent/writer.js b/packages/dd-trace/src/exporters/agent/writer.js index d81f197395a..3439b0b0e6e 100644 --- a/packages/dd-trace/src/exporters/agent/writer.js +++ b/packages/dd-trace/src/exporters/agent/writer.js @@ -17,19 +17,21 @@ const firstFlushChannel = channel('dd-trace:exporter:first-flush') class AgentWriter extends BaseWriter { #request = commonRequest #requestTracker + #onFlush constructor (...args) { super({ ...args[0], beforeFirstFlush: () => firstFlushChannel.publish(), }) - const { prioritySampler, lookup, protocolVersion, headers, isTestOptimization } = args[0] + const { prioritySampler, lookup, protocolVersion, headers, isTestOptimization, onFlush } = args[0] const AgentEncoder = getEncoder(protocolVersion) this._prioritySampler = prioritySampler this._lookup = lookup this._protocolVersion = protocolVersion this._headers = headers + this.#onFlush = onFlush this._encoder = new AgentEncoder(this) if (isTestOptimization) { this.#request = require('../../ci-visibility/exporters/request') @@ -46,6 +48,12 @@ class AgentWriter extends BaseWriter { * @returns {void} */ flush (done, options) { + const flush = callback => this.flushDirect(callback, options) + if (this.#onFlush) return this.#onFlush(flush, done) + flush(done) + } + + flushDirect (done, options) { if (this.#requestTracker) { this.#requestTracker.flush(done, options) return diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index b3acca1ec41..2930cbc8108 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -1,5 +1,6 @@ 'use strict' +const log = require('../../log') const { Writer } = require('./writer') class SpanStatsExporter { @@ -21,8 +22,9 @@ class SpanStatsExporter { this._writer.append(payload) try { this.#flush(complete) - } catch { + } catch (error) { // `#flush` has notified the boundary request; keep waiting for prior exports. + log.error('Failed to flush span stats: %s', error.message) } return } diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 455919ec654..6bdae0cf538 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -13,7 +13,7 @@ const nomenclature = require('./service-naming') const PluginManager = require('./plugin_manager') const NoopDogStatsDClient = require('./noop/dogstatsd') const { IS_SERVERLESS, initializeServerlessTelemetry } = require('./serverless') -const { registerTelemetryFlusher } = require('./flush') +const { flushAll, registerTelemetryFlusher } = require('./flush') const processTags = require('./process-tags') const { isTrue } = require('./util') const { @@ -103,6 +103,11 @@ class Tracer extends NoopProxy { this._pluginManager = new PluginManager(this) this.dogstatsd = new NoopDogStatsDClient() this._tracingInitialized = false + // Keep a stable lifecycle owner even when tracing is disabled. In that + // configuration logs and metrics can still have registered flushers. + this._serverlessTelemetry = { + flushAll: (done, options) => flushAll(this._tracer, done, options), + } this._flare = new LazyModule(() => require('./flare')) this.setBaggageItem = setBaggageItem this.getBaggageItem = getBaggageItem @@ -395,11 +400,12 @@ class Tracer extends NoopProxy { if (this._tracingInitialized) { this._tracer.configure(config) this._pluginManager.configure(config) - initializeServerlessTelemetry(this._tracer) DynamicInstrumentation.configure(config) setStartupLogPluginManager(this._pluginManager) startupLog() } + + initializeServerlessTelemetry(this._serverlessTelemetry) } /** diff --git a/packages/dd-trace/test/dogstatsd.spec.js b/packages/dd-trace/test/dogstatsd.spec.js index 1c30b47d92d..17cb0d3c5ae 100644 --- a/packages/dd-trace/test/dogstatsd.spec.js +++ b/packages/dd-trace/test/dogstatsd.spec.js @@ -248,6 +248,28 @@ describe('dogstatsd', () => { }) }) + it('joins an already in-flight UDP flush', (done) => { + let completeFirstFlush + udp4.send = sinon.stub().callsFake((...args) => { + completeFirstFlush = args.at(-1) + }) + client = createDogStatsDClient() + client.gauge('test.avg', 1) + client.flush() + + client.flush(() => { + try { + sinon.assert.calledOnce(udp4.send) + done() + } catch (error) { + done(error) + } + }) + + assert.strictEqual(completeFirstFlush instanceof Function, true) + completeFirstFlush() + }) + it('logs the metric count and the UDP transport on a non-empty flush', () => { client = createDogStatsDClient() diff --git a/packages/dd-trace/test/exporters/agent/exporter.spec.js b/packages/dd-trace/test/exporters/agent/exporter.spec.js index b699220d8a3..ee9a04d0c06 100644 --- a/packages/dd-trace/test/exporters/agent/exporter.spec.js +++ b/packages/dd-trace/test/exporters/agent/exporter.spec.js @@ -18,6 +18,7 @@ describe('Exporter', () => { let writer let prioritySampler let span + let writerOptions beforeEach(() => { url = 'http://www.example.com:8126' @@ -29,7 +30,10 @@ describe('Exporter', () => { setUrl: sinon.spy(), } prioritySampler = {} - Writer = sinon.stub().returns(writer) + Writer = sinon.stub().callsFake(options => { + writerOptions = options + return writer + }) Exporter = proxyquire('../../../src/exporters/agent', { './writer': Writer, @@ -128,6 +132,24 @@ describe('Exporter', () => { sinon.assert.calledOnce(flushed) }) + it('waits for an encoder-triggered writer flush already in flight', () => { + const callbacks = [] + const flushDirect = sinon.spy(done => callbacks.push(done)) + writer.flushDirect = flushDirect + writer.flush = sinon.spy(done => writerOptions.onFlush(flushDirect, done)) + exporter = new Exporter({ url, flushInterval: 0 }, prioritySampler) + const flushed = sinon.spy() + + // This is the path the encoder uses when it crosses its soft limit. + exporter._writer.flush() + exporter.flush(flushed) + + callbacks[1]() + sinon.assert.notCalled(flushed) + callbacks[0]() + sinon.assert.calledOnce(flushed) + }) + it('does not retain a failed writer flush', () => { writer.flush = sinon.stub() writer.flush.onFirstCall().throws(new Error('encode failed')) diff --git a/packages/dd-trace/test/exporters/agent/writer.spec.js b/packages/dd-trace/test/exporters/agent/writer.spec.js index 7ed70d40476..f92a48d6866 100644 --- a/packages/dd-trace/test/exporters/agent/writer.spec.js +++ b/packages/dd-trace/test/exporters/agent/writer.spec.js @@ -109,6 +109,20 @@ function describeWriter (protocolVersion) { writer.flush(done) }) + it('routes flushes through the configured lifecycle hook', (done) => { + const onFlush = sinon.spy((flush, done) => flush(done)) + writer = new Writer({ url, prioritySampler, protocolVersion, onFlush }) + + writer.flush(() => { + try { + sinon.assert.calledOnce(onFlush) + done() + } catch (error) { + done(error) + } + }) + }) + it('should flush its traces to the agent, and call callback', (done) => { const expectedData = Buffer.from('prefixed') diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index f34efcbd994..aefad42e8b3 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -15,6 +15,7 @@ describe('span-stats exporter', () => { let exporter let Writer let writer + let log beforeEach(() => { url = new URL('http://www.example.com:8126') @@ -23,9 +24,11 @@ describe('span-stats exporter', () => { flush: sinon.spy(), } Writer = sinon.stub().returns(writer) + log = { error: sinon.spy() } Exporter = proxyquire('../../../src/exporters/span-stats', { './writer': { Writer }, + '../../log': log, }).SpanStatsExporter }) @@ -84,6 +87,7 @@ describe('span-stats exporter', () => { sinon.assert.notCalled(done) inFlightDone() sinon.assert.calledOnce(done) + sinon.assert.calledOnceWithExactly(log.error, 'Failed to flush span stats: %s', 'encode failed') }) it('should set url from config', () => { diff --git a/packages/dd-trace/test/proxy.spec.js b/packages/dd-trace/test/proxy.spec.js index f835a1c0fc1..c72e4a2ae15 100644 --- a/packages/dd-trace/test/proxy.spec.js +++ b/packages/dd-trace/test/proxy.spec.js @@ -48,6 +48,8 @@ describe('TracerProxy', () => { let OpenFeatureProvider let openfeatureProvider let registerTelemetryFlusher + let initializeServerlessTelemetry + let flushAll beforeEach(() => { process.env.DD_TRACE_MOCHA_ENABLED = 'false' @@ -185,6 +187,8 @@ describe('TracerProxy', () => { } registerTelemetryFlusher = sinon.stub().returns(() => {}) + initializeServerlessTelemetry = sinon.spy() + flushAll = sinon.spy() profiler = { start: sinon.spy(), @@ -275,8 +279,9 @@ describe('TracerProxy', () => { './openfeature/flagging_provider': OpenFeatureProvider, './serverless': { IS_SERVERLESS: false, + initializeServerlessTelemetry, }, - './flush': { registerTelemetryFlusher }, + './flush': { flushAll, registerTelemetryFlusher }, }) proxy = new ProxyClass() @@ -604,6 +609,19 @@ describe('TracerProxy', () => { sinon.assert.calledOnceWithExactly(runtimeMetrics.flush, done) }) + it('registers Vercel telemetry retention when tracing is disabled', () => { + config.DD_TRACE_ENABLED = false + + proxy.init() + + sinon.assert.calledOnce(initializeServerlessTelemetry) + const telemetry = initializeServerlessTelemetry.firstCall.args[0] + assert.strictEqual(typeof telemetry.flushAll, 'function') + const done = sinon.spy() + telemetry.flushAll(done) + sinon.assert.calledOnceWithExactly(flushAll, proxy._tracer, done, undefined) + }) + it('should expose noop metrics methods prior to initialization', () => { proxy.dogstatsd.increment('foo') }) diff --git a/packages/dd-trace/test/serverless.spec.js b/packages/dd-trace/test/serverless.spec.js index 89d36b942fe..043f825b9ee 100644 --- a/packages/dd-trace/test/serverless.spec.js +++ b/packages/dd-trace/test/serverless.spec.js @@ -17,6 +17,7 @@ const { initializeServerlessTelemetry, } = require('../src/serverless') const { registerVercelTelemetryRetention } = require('../src/serverless/vercel') +const { flushAll, registerTelemetryFlusher } = require('../src/flush') const Tracer = require('../src/tracer') const { initializeOpenTelemetryLogs } = require('../src/opentelemetry/logs') const { initializeOpenTelemetryMetrics } = require('../src/opentelemetry/metrics') @@ -275,6 +276,40 @@ describe('Vercel telemetry retention', () => { } }) + it('retains a configured telemetry-only pipeline without a trace exporter', async () => { + let retained + const completeTelemetry = [] + let flushes = 0 + globalThis[requestContext] = { + get: () => ({ waitUntil: promise => { retained = promise } }), + } + const telemetryFlusher = done => { + flushes++ + completeTelemetry.push(done) + } + const unregisterTelemetry = registerTelemetryFlusher(telemetryFlusher) + const unregister = registerVercelTelemetryRetention({ + flushAll: (done, options) => flushAll(undefined, done, options), + }) + try { + channel('apm:http:server:request:finish').publish({}) + await new Promise(resolve => setImmediate(resolve)) + + assert.ok(flushes >= 1) + assert.ok(completeTelemetry.every(done => typeof done === 'function')) + let settled = false + retained.then(() => { settled = true }) + await new Promise(resolve => setImmediate(resolve)) + assert.strictEqual(settled, false) + + for (const done of completeTelemetry) done() + await retained + } finally { + unregister() + unregisterTelemetry() + } + }) + it('retains telemetry again when an outer Vercel response follows a nested request', async () => { const retained = [] const flushes = [] diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index 7aaed371459..345ec80f5e3 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -70,6 +70,19 @@ describe('Tracer', () => { unregister() }) + it('flushes registered telemetry pipelines without a trace exporter', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + const telemetryFlusher = sinon.stub().callsFake(done => done()) + const unregister = registerTelemetryFlusher(telemetryFlusher) + const done = sinon.spy() + + flushAll(undefined, done) + + sinon.assert.calledOnce(telemetryFlusher) + sinon.assert.calledOnce(done) + unregister() + }) + it('bounds configured telemetry flushing', () => { const { flushAll, registerTelemetryFlusher } = require('../src/flush') const timeout = sinon.stub(global, 'setTimeout') From 27b2693a7695b5484421b35a2c01893c2342acf9 Mon Sep 17 00:00:00 2001 From: William Conti Date: Tue, 18 Aug 2026 15:32:08 -0400 Subject: [PATCH 31/31] fix(serverless): retain remaining Vercel telemetry --- packages/dd-trace/src/dogstatsd.js | 6 ++++-- .../src/exporters/span-stats/index.js | 20 ++++++++++++++++-- .../src/exporters/span-stats/writer.js | 15 ++++++++++++- packages/dd-trace/src/flush.js | 20 ++++++++++++------ packages/dd-trace/src/proxy.js | 5 ++++- packages/dd-trace/src/span_stats.js | 16 ++++++++++---- packages/dd-trace/test/dogstatsd.spec.js | 15 +++++++++++++ .../exporters/span-stats/exporter.spec.js | 17 ++++++++++++++- .../test/exporters/span-stats/writer.spec.js | 11 ++++++++++ packages/dd-trace/test/span_stats.spec.js | 21 +++++++++++++++++++ packages/dd-trace/test/tracer.spec.js | 17 +++++++++++++++ 11 files changed, 146 insertions(+), 17 deletions(-) diff --git a/packages/dd-trace/src/dogstatsd.js b/packages/dd-trace/src/dogstatsd.js index 495210d2262..c5c31014dd6 100644 --- a/packages/dd-trace/src/dogstatsd.js +++ b/packages/dd-trace/src/dogstatsd.js @@ -8,6 +8,7 @@ const request = require('./exporters/common/request') const log = require('./log') const Histogram = require('./histogram') const { entityId } = require('./exporters/common/docker') +const { registerTelemetryFlusher } = require('./flush') const legacyStorage = storage('legacy') @@ -406,6 +407,7 @@ class CustomMetrics { setInterval(flush, 10 * 1000).unref?.() globalThis[Symbol.for('dd-trace')].beforeExitHandlers.add(flush) + registerTelemetryFlusher(done => this.flush(done)) } increment (stat, value = 1, tags) { @@ -428,8 +430,8 @@ class CustomMetrics { this.#client.histogram(stat, value, CustomMetrics.tagTranslator(tags)) } - flush () { - return this.#client.flush() + flush (done) { + return this.#client.flush(done) } /** diff --git a/packages/dd-trace/src/exporters/span-stats/index.js b/packages/dd-trace/src/exporters/span-stats/index.js index 2930cbc8108..99c5b73e14f 100644 --- a/packages/dd-trace/src/exporters/span-stats/index.js +++ b/packages/dd-trace/src/exporters/span-stats/index.js @@ -8,7 +8,7 @@ class SpanStatsExporter { constructor (config) { this._url = config.url - this._writer = new Writer({ url: this._url }) + this._writer = new Writer({ url: this._url, onFlush: this.#trackWriterFlush.bind(this) }) } export (payload, done) { @@ -50,7 +50,23 @@ class SpanStatsExporter { for (const callback of flush.callbacks) callback() } try { - this._writer.flush(complete) + const flushWriter = this._writer.flushDirect ?? this._writer.flush + flushWriter.call(this._writer, complete) + } catch (error) { + complete() + throw error + } + } + + #trackWriterFlush (flush, done) { + const activeFlush = { callbacks: done ? [done] : [] } + this.#activeFlushes.add(activeFlush) + const complete = () => { + this.#activeFlushes.delete(activeFlush) + for (const callback of activeFlush.callbacks) callback() + } + try { + flush(complete) } catch (error) { complete() throw error diff --git a/packages/dd-trace/src/exporters/span-stats/writer.js b/packages/dd-trace/src/exporters/span-stats/writer.js index a6a6cecb3a4..863ef36f747 100644 --- a/packages/dd-trace/src/exporters/span-stats/writer.js +++ b/packages/dd-trace/src/exporters/span-stats/writer.js @@ -9,12 +9,25 @@ const request = require('../common/request') const log = require('../../log') class Writer extends BaseWriter { - constructor ({ url }) { + #onFlush + + constructor ({ url, onFlush }) { super(...arguments) this._url = url + this.#onFlush = onFlush this._encoder = new SpanStatsEncoder(this) } + flush (done, options) { + const flush = callback => this.flushDirect(callback, options) + if (this.#onFlush) return this.#onFlush(flush, done) + flush(done) + } + + flushDirect (done, options) { + super.flush(done, options) + } + _sendPayload (data, _, done) { makeRequest(data, this._url, (err, res) => { if (err) { diff --git a/packages/dd-trace/src/flush.js b/packages/dd-trace/src/flush.js index ef961f8d633..2b62e5dc64b 100644 --- a/packages/dd-trace/src/flush.js +++ b/packages/dd-trace/src/flush.js @@ -8,17 +8,20 @@ const log = require('./log') /** @type {Set} */ const telemetryFlushers = new Set() +const postTraceTelemetryFlushers = new Set() /** * Registers a configured telemetry pipeline so serverless lifecycle retention * waits for its final export alongside trace delivery. * @param {TelemetryFlusher} flusher + * @param {{ afterTrace?: boolean }} [options] * @returns {() => void} Removes this pipeline when its provider is replaced. */ -function registerTelemetryFlusher (flusher) { - telemetryFlushers.add(flusher) +function registerTelemetryFlusher (flusher, options) { + const flushers = options?.afterTrace ? postTraceTelemetryFlushers : telemetryFlushers + flushers.add(flusher) // Avoid retaining a replaced provider or flushing it alongside the new one. - return () => telemetryFlushers.delete(flusher) + return () => flushers.delete(flusher) } /** @@ -35,7 +38,7 @@ function flushAll (tracer, done, options) { const traceFlusher = traceExporter?.flush const spanStatsFlusher = tracer?._processor?._stats?.forceFlush // TODO: Include DSM after DataStreamsProcessor exposes a completion-aware flush API. - let pending = telemetryFlushers.size + + let pending = telemetryFlushers.size + postTraceTelemetryFlushers.size + (typeof traceFlusher === 'function' ? 1 : 0) + (typeof spanStatsFlusher === 'function' ? 1 : 0) let completed = false @@ -59,12 +62,13 @@ function flushAll (tracer, done, options) { }, options.timeout) } - const flush = flusher => { + const flush = (flusher, afterFlushed) => { let flushed = false const onFlushed = error => { if (flushed) return flushed = true if (error) log.error('Error flushing telemetry pipeline:', error) + afterFlushed?.() complete() } try { @@ -76,7 +80,11 @@ function flushAll (tracer, done, options) { } if (typeof traceFlusher === 'function') { - flush(done => traceFlusher.call(traceExporter, done)) + flush(done => traceFlusher.call(traceExporter, done), () => { + for (const flusher of postTraceTelemetryFlushers) flush(flusher) + }) + } else { + for (const flusher of postTraceTelemetryFlushers) flush(flusher) } if (typeof spanStatsFlusher === 'function') { flush(done => spanStatsFlusher.call(tracer._processor._stats, done)) diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 6bdae0cf538..19ac7b63bd5 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -265,7 +265,10 @@ class Tracer extends NoopProxy { unregisterRuntimeMetricsFlusher = undefined if (config.runtimeMetrics.enabled) { runtimeMetrics.start(config) - unregisterRuntimeMetricsFlusher = registerTelemetryFlusher(done => runtimeMetrics.flush(done)) + // Agent trace response metrics are recorded asynchronously, so drain + // runtime metrics after the trace export has completed. + unregisterRuntimeMetricsFlusher = registerTelemetryFlusher( + done => runtimeMetrics.flush(done), { afterTrace: true }) } this.#updateTracing(config) diff --git a/packages/dd-trace/src/span_stats.js b/packages/dd-trace/src/span_stats.js index d35d3798fa8..6e10d751df5 100644 --- a/packages/dd-trace/src/span_stats.js +++ b/packages/dd-trace/src/span_stats.js @@ -262,10 +262,18 @@ class SpanStatsProcessor { ProcessTags: processTags.serialized, }, done) } else if (this.otlpExporter && drained.length > 0) { - this.otlpExporter.export(drained, this.bucketSizeNs, () => { - if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) - else done?.() - }) + if (typeof this.otlpExporter.flush === 'function' && done) { + // Snapshot requests already in flight before starting this boundary + // export, so a later invocation cannot extend this lifecycle barrier. + let pending = 2 + const complete = () => { + if (--pending === 0) done() + } + this.otlpExporter.flush(complete) + this.otlpExporter.export(drained, this.bucketSizeNs, complete) + } else { + this.otlpExporter.export(drained, this.bucketSizeNs, done) + } } else if (this.otlpExporter) { if (typeof this.otlpExporter.flush === 'function') this.otlpExporter.flush(done) else done?.() diff --git a/packages/dd-trace/test/dogstatsd.spec.js b/packages/dd-trace/test/dogstatsd.spec.js index 17cb0d3c5ae..2a25eca09c1 100644 --- a/packages/dd-trace/test/dogstatsd.spec.js +++ b/packages/dd-trace/test/dogstatsd.spec.js @@ -32,6 +32,7 @@ describe('dogstatsd', () => { let assertData let docker let log + let registerTelemetryFlusher beforeEach((done) => { udp6 = { @@ -74,10 +75,12 @@ describe('dogstatsd', () => { docker = {} log = { debug: sinon.stub(), error: sinon.stub() } + registerTelemetryFlusher = sinon.stub() const dogstatsd = proxyquire.noPreserveCache().noCallThru()('../src/dogstatsd', { dgram, '../../datadog-core': datadogCore, + './flush': { registerTelemetryFlusher }, './exporters/common/docker': docker, './log': log, }) @@ -518,6 +521,18 @@ describe('dogstatsd', () => { }) describe('CustomMetrics', () => { + it('registers its aggregated metrics flush with the telemetry lifecycle', () => { + udp4.send = sinon.stub().callsFake((_buffer, _offset, _length, _port, _host, done) => done()) + client = createCustomMetrics() + client.gauge('test.avg', 10) + const done = sinon.spy() + + registerTelemetryFlusher.firstCall.args[0](done) + + sinon.assert.calledOnce(done) + sinon.assert.calledOnce(udp4.send) + }) + it('.gauge()', () => { client = createCustomMetrics() diff --git a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js index aefad42e8b3..34b01df4e15 100644 --- a/packages/dd-trace/test/exporters/span-stats/exporter.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/exporter.spec.js @@ -60,6 +60,21 @@ describe('span-stats exporter', () => { sinon.assert.calledOnce(done) }) + it('waits for an encoder-triggered export during flush', () => { + exporter = new Exporter({ url }) + const onFlush = Writer.firstCall.args[0].onFlush + let automaticDone + onFlush(done => { automaticDone = done }) + writer.flush = sinon.stub().callsFake(done => done()) + const done = sinon.spy() + + exporter.flush(done) + + sinon.assert.notCalled(done) + automaticDone() + sinon.assert.calledOnce(done) + }) + it('does not retain a failed writer flush', () => { writer.flush = sinon.stub() writer.flush.onFirstCall().throws(new Error('encode failed')) @@ -96,7 +111,7 @@ describe('span-stats exporter', () => { exporter = new Exporter({ url }) assert.strictEqual(exporter._url.toString(), url.toString()) - sinon.assert.calledWith(Writer, { + sinon.assert.calledWithMatch(Writer, { url: exporter._url, }) }) diff --git a/packages/dd-trace/test/exporters/span-stats/writer.spec.js b/packages/dd-trace/test/exporters/span-stats/writer.spec.js index 23919126944..202612c5dcc 100644 --- a/packages/dd-trace/test/exporters/span-stats/writer.spec.js +++ b/packages/dd-trace/test/exporters/span-stats/writer.spec.js @@ -77,6 +77,17 @@ describe('span-stats writer', () => { writer.flush(done) }) + it('routes encoder-triggered flushes through the configured lifecycle hook', () => { + const onFlush = sinon.stub().callsFake((flush, done) => flush(done)) + writer = new Writer({ url, onFlush }) + encoder.count.returns(1) + encoder.encode.callsFake(() => writer.flush()) + + writer.append([span]) + + sinon.assert.calledOnce(onFlush) + }) + it('should flush to the agent, and call callback', (done) => { const expectedData = Buffer.from('prefixed') diff --git a/packages/dd-trace/test/span_stats.spec.js b/packages/dd-trace/test/span_stats.spec.js index 0e8b50e76de..4152d109854 100644 --- a/packages/dd-trace/test/span_stats.spec.js +++ b/packages/dd-trace/test/span_stats.spec.js @@ -663,6 +663,27 @@ describe('SpanStatsProcessor', () => { assert.strictEqual(p.buckets.size, 0) }) + it('snapshots prior OTLP exports before starting the boundary export', () => { + let priorDone + let exportDone + const exporter = { + flush: sinon.stub().callsFake(done => { priorDone = done }), + export: sinon.stub().callsFake((_drained, _bucketSizeNs, done) => { exportDone = done }), + } + const p = new SpanStatsProcessor(config, exporter) + clearTimeout(p.timer) + p.onSpanFinished(topLevelSpan) + const done = sinon.spy() + + p.forceFlush(done) + + sinon.assert.callOrder(exporter.flush, exporter.export) + exportDone() + sinon.assert.notCalled(done) + priorDone() + sinon.assert.calledOnce(done) + }) + it('force flushes pending agent span statistics', () => { exporter.export.resetHistory() exporter.flush.resetHistory() diff --git a/packages/dd-trace/test/tracer.spec.js b/packages/dd-trace/test/tracer.spec.js index 345ec80f5e3..8b7a5062502 100644 --- a/packages/dd-trace/test/tracer.spec.js +++ b/packages/dd-trace/test/tracer.spec.js @@ -70,6 +70,23 @@ describe('Tracer', () => { unregister() }) + it('flushes post-trace telemetry after the trace exporter completes', () => { + const { flushAll, registerTelemetryFlusher } = require('../src/flush') + let traceDone + const tracer = { _exporter: { flush: sinon.stub().callsFake(done => { traceDone = done }) } } + const runtimeMetricsFlusher = sinon.stub().callsFake(done => done()) + const unregister = registerTelemetryFlusher(runtimeMetricsFlusher, { afterTrace: true }) + const done = sinon.spy() + + flushAll(tracer, done) + + sinon.assert.notCalled(runtimeMetricsFlusher) + traceDone() + sinon.assert.calledOnce(runtimeMetricsFlusher) + sinon.assert.calledOnce(done) + unregister() + }) + it('flushes registered telemetry pipelines without a trace exporter', () => { const { flushAll, registerTelemetryFlusher } = require('../src/flush') const telemetryFlusher = sinon.stub().callsFake(done => done())