From b4f99e80d77cfe8361e20c9aa1a5ca1efe94d89e Mon Sep 17 00:00:00 2001 From: Thomas Watson Date: Tue, 7 Jan 2025 13:55:10 +0100 Subject: [PATCH 1/8] [DI] Batch outgoing http requests (#5007) --- integration-tests/debugger/basic.spec.js | 282 ++++++++++-------- .../debugger/snapshot-pruning.spec.js | 2 +- integration-tests/debugger/snapshot.spec.js | 10 +- integration-tests/debugger/utils.js | 8 +- .../src/debugger/devtools_client/config.js | 3 +- .../src/debugger/devtools_client/index.js | 5 +- .../debugger/devtools_client/json-buffer.js | 36 +++ .../src/debugger/devtools_client/send.js | 38 ++- .../src/debugger/devtools_client/status.js | 11 +- .../devtools_client/json-buffer.spec.js | 45 +++ .../debugger/devtools_client/send.spec.js | 111 +++++++ .../debugger/devtools_client/status.spec.js | 97 ++++-- .../test/debugger/devtools_client/utils.js | 20 +- 13 files changed, 483 insertions(+), 185 deletions(-) create mode 100644 packages/dd-trace/src/debugger/devtools_client/json-buffer.js create mode 100644 packages/dd-trace/test/debugger/devtools_client/json-buffer.spec.js create mode 100644 packages/dd-trace/test/debugger/devtools_client/send.spec.js diff --git a/integration-tests/debugger/basic.spec.js b/integration-tests/debugger/basic.spec.js index aa6a1881d33..f51278bc2ee 100644 --- a/integration-tests/debugger/basic.spec.js +++ b/integration-tests/debugger/basic.spec.js @@ -47,20 +47,22 @@ describe('Dynamic Instrumentation', function () { }) t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - assertUUID(payload.debugger.diagnostics.runtimeId) - - if (payload.debugger.diagnostics.status === 'INSTALLED') { - t.axios.get(t.breakpoint.url) - .then((response) => { - assert.strictEqual(response.status, 200) - assert.deepStrictEqual(response.data, { hello: 'bar' }) - }) - .catch(done) - } else { - endIfDone() - } + payload.forEach((event) => { + const expected = expectedPayloads.shift() + assertObjectContains(event, expected) + assertUUID(event.debugger.diagnostics.runtimeId) + + if (event.debugger.diagnostics.status === 'INSTALLED') { + t.axios.get(t.breakpoint.url) + .then((response) => { + assert.strictEqual(response.status, 200) + assert.deepStrictEqual(response.data, { hello: 'bar' }) + }) + .catch(done) + } else { + endIfDone() + } + }) }) t.agent.addRemoteConfig(t.rcConfig) @@ -108,11 +110,13 @@ describe('Dynamic Instrumentation', function () { }) t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - assertUUID(payload.debugger.diagnostics.runtimeId) - if (payload.debugger.diagnostics.status === 'INSTALLED') triggers.shift()() - endIfDone() + payload.forEach((event) => { + const expected = expectedPayloads.shift() + assertObjectContains(event, expected) + assertUUID(event.debugger.diagnostics.runtimeId) + if (event.debugger.diagnostics.status === 'INSTALLED') triggers.shift()() + endIfDone() + }) }) t.agent.addRemoteConfig(t.rcConfig) @@ -147,18 +151,20 @@ describe('Dynamic Instrumentation', function () { }) t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - assertUUID(payload.debugger.diagnostics.runtimeId) - - if (payload.debugger.diagnostics.status === 'INSTALLED') { - t.agent.removeRemoteConfig(t.rcConfig.id) - // Wait a little to see if we get any follow-up `debugger-diagnostics` messages - setTimeout(() => { - payloadsProcessed = true - endIfDone() - }, pollInterval * 2 * 1000) // wait twice as long as the RC poll interval - } + payload.forEach((event) => { + const expected = expectedPayloads.shift() + assertObjectContains(event, expected) + assertUUID(event.debugger.diagnostics.runtimeId) + + if (event.debugger.diagnostics.status === 'INSTALLED') { + t.agent.removeRemoteConfig(t.rcConfig.id) + // Wait a little to see if we get any follow-up `debugger-diagnostics` messages + setTimeout(() => { + payloadsProcessed = true + endIfDone() + }, pollInterval * 2 * 1000) // wait twice as long as the RC poll interval + } + }) }) t.agent.addRemoteConfig(t.rcConfig) @@ -206,19 +212,21 @@ describe('Dynamic Instrumentation', function () { }] t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - const { diagnostics } = payload.debugger - assertUUID(diagnostics.runtimeId) - - if (diagnostics.status === 'ERROR') { - assert.property(diagnostics, 'exception') - assert.hasAllKeys(diagnostics.exception, ['message', 'stacktrace']) - assert.typeOf(diagnostics.exception.message, 'string') - assert.typeOf(diagnostics.exception.stacktrace, 'string') - } + payload.forEach((event) => { + const expected = expectedPayloads.shift() + assertObjectContains(event, expected) + const { diagnostics } = event.debugger + assertUUID(diagnostics.runtimeId) + + if (diagnostics.status === 'ERROR') { + assert.property(diagnostics, 'exception') + assert.hasAllKeys(diagnostics.exception, ['message', 'stacktrace']) + assert.typeOf(diagnostics.exception.message, 'string') + assert.typeOf(diagnostics.exception.stacktrace, 'string') + } - endIfDone() + endIfDone() + }) }) t.agent.addRemoteConfig({ @@ -255,10 +263,12 @@ describe('Dynamic Instrumentation', function () { ] t.agent.on('debugger-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') triggers.shift()().catch(done) + payload.forEach((event) => { + if (event.debugger.diagnostics.status === 'INSTALLED') triggers.shift()().catch(done) + }) }) - t.agent.on('debugger-input', ({ payload }) => { + t.agent.on('debugger-input', ({ payload: [payload] }) => { assert.strictEqual(payload.message, expectedMessages.shift()) if (expectedMessages.length === 0) done() }) @@ -268,17 +278,19 @@ describe('Dynamic Instrumentation', function () { it('should not trigger if probe is deleted', function (done) { t.agent.on('debugger-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') { - t.agent.once('remote-confg-responded', async () => { - await t.axios.get(t.breakpoint.url) - // We want to wait enough time to see if the client triggers on the breakpoint so that the test can fail - // if it does, but not so long that the test times out. - // TODO: Is there some signal we can use instead of a timer? - setTimeout(done, pollInterval * 2 * 1000) // wait twice as long as the RC poll interval - }) + payload.forEach((event) => { + if (event.debugger.diagnostics.status === 'INSTALLED') { + t.agent.once('remote-confg-responded', async () => { + await t.axios.get(t.breakpoint.url) + // We want to wait enough time to see if the client triggers on the breakpoint so that the test can fail + // if it does, but not so long that the test times out. + // TODO: Is there some signal we can use instead of a timer? + setTimeout(done, pollInterval * 2 * 1000) // wait twice as long as the RC poll interval + }) - t.agent.removeRemoteConfig(t.rcConfig.id) - } + t.agent.removeRemoteConfig(t.rcConfig.id) + } + }) }) t.agent.on('debugger-input', () => { @@ -291,8 +303,7 @@ describe('Dynamic Instrumentation', function () { describe('sampling', function () { it('should respect sampling rate for single probe', function (done) { - let start, timer - let payloadsReceived = 0 + let prev, timer const rcConfig = t.generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) function triggerBreakpointContinuously () { @@ -301,27 +312,26 @@ describe('Dynamic Instrumentation', function () { } t.agent.on('debugger-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') triggerBreakpointContinuously() + payload.forEach((event) => { + if (event.debugger.diagnostics.status === 'INSTALLED') triggerBreakpointContinuously() + }) }) - t.agent.on('debugger-input', () => { - payloadsReceived++ - if (payloadsReceived === 1) { - start = Date.now() - } else if (payloadsReceived === 2) { - const duration = Date.now() - start - clearTimeout(timer) - - // Allow for a variance of -5/+50ms (time will tell if this is enough) - assert.isAbove(duration, 995) - assert.isBelow(duration, 1050) - - // Wait at least a full sampling period, to see if we get any more payloads - timer = setTimeout(done, 1250) - } else { - clearTimeout(timer) - done(new Error('Too many payloads received!')) - } + t.agent.on('debugger-input', ({ payload }) => { + payload.forEach(({ 'debugger.snapshot': { timestamp } }) => { + if (prev !== undefined) { + const duration = timestamp - prev + clearTimeout(timer) + + // Allow for a variance of +50ms (time will tell if this is enough) + assert.isAtLeast(duration, 1000) + assert.isBelow(duration, 1050) + + // Wait at least a full sampling period, to see if we get any more payloads + timer = setTimeout(done, 1250) + } + prev = timestamp + }) }) t.agent.addRemoteConfig(rcConfig) @@ -332,14 +342,12 @@ describe('Dynamic Instrumentation', function () { const rcConfig2 = t.breakpoints[1].generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) const state = { [rcConfig1.config.id]: { - payloadsReceived: 0, tiggerBreakpointContinuously () { t.axios.get(t.breakpoints[0].url).catch(done) this.timer = setTimeout(this.tiggerBreakpointContinuously.bind(this), 10) } }, [rcConfig2.config.id]: { - payloadsReceived: 0, tiggerBreakpointContinuously () { t.axios.get(t.breakpoints[1].url).catch(done) this.timer = setTimeout(this.tiggerBreakpointContinuously.bind(this), 10) @@ -348,29 +356,29 @@ describe('Dynamic Instrumentation', function () { } t.agent.on('debugger-diagnostics', ({ payload }) => { - const { probeId, status } = payload.debugger.diagnostics - if (status === 'INSTALLED') state[probeId].tiggerBreakpointContinuously() + payload.forEach((event) => { + const { probeId, status } = event.debugger.diagnostics + if (status === 'INSTALLED') state[probeId].tiggerBreakpointContinuously() + }) }) t.agent.on('debugger-input', ({ payload }) => { - const _state = state[payload['debugger.snapshot'].probe.id] - _state.payloadsReceived++ - if (_state.payloadsReceived === 1) { - _state.start = Date.now() - } else if (_state.payloadsReceived === 2) { - const duration = Date.now() - _state.start - clearTimeout(_state.timer) - - // Allow for a variance of -5/+50ms (time will tell if this is enough) - assert.isAbove(duration, 995) - assert.isBelow(duration, 1050) - - // Wait at least a full sampling period, to see if we get any more payloads - _state.timer = setTimeout(doneWhenCalledTwice, 1250) - } else { - clearTimeout(_state.timer) - done(new Error('Too many payloads received!')) - } + payload.forEach((result) => { + const _state = state[result['debugger.snapshot'].probe.id] + const { timestamp } = result['debugger.snapshot'] + if (_state.prev !== undefined) { + const duration = timestamp - _state.prev + clearTimeout(_state.timer) + + // Allow for a variance of +50ms (time will tell if this is enough) + assert.isAtLeast(duration, 1000) + assert.isBelow(duration, 1050) + + // Wait at least a full sampling period, to see if we get any more payloads + _state.timer = setTimeout(doneWhenCalledTwice, 1250) + } + _state.prev = timestamp + }) }) t.agent.addRemoteConfig(rcConfig1) @@ -387,39 +395,42 @@ describe('Dynamic Instrumentation', function () { it('should remove the last breakpoint completely before trying to add a new one', function (done) { const rcConfig2 = t.generateRemoteConfig() - t.agent.on('debugger-diagnostics', ({ payload: { debugger: { diagnostics: { status, probeId } } } }) => { - if (status !== 'INSTALLED') return - - if (probeId === t.rcConfig.config.id) { - // First INSTALLED payload: Try to trigger the race condition. - t.agent.removeRemoteConfig(t.rcConfig.id) - t.agent.addRemoteConfig(rcConfig2) - } else { - // Second INSTALLED payload: Perform an HTTP request to see if we successfully handled the race condition. - let finished = false - - // If the race condition occurred, the debugger will have been detached from the main thread and the new - // probe will never trigger. If that's the case, the following timer will fire: - const timer = setTimeout(() => { - done(new Error('Race condition occurred!')) - }, 1000) - - // If we successfully handled the race condition, the probe will trigger, we'll get a probe result and the - // following event listener will be called: - t.agent.once('debugger-input', () => { - clearTimeout(timer) - finished = true - done() - }) + t.agent.on('debugger-diagnostics', ({ payload }) => { + payload.forEach((event) => { + const { probeId, status } = event.debugger.diagnostics + if (status !== 'INSTALLED') return + + if (probeId === t.rcConfig.config.id) { + // First INSTALLED payload: Try to trigger the race condition. + t.agent.removeRemoteConfig(t.rcConfig.id) + t.agent.addRemoteConfig(rcConfig2) + } else { + // Second INSTALLED payload: Perform an HTTP request to see if we successfully handled the race condition. + let finished = false + + // If the race condition occurred, the debugger will have been detached from the main thread and the new + // probe will never trigger. If that's the case, the following timer will fire: + const timer = setTimeout(() => { + done(new Error('Race condition occurred!')) + }, 2000) + + // If we successfully handled the race condition, the probe will trigger, we'll get a probe result and the + // following event listener will be called: + t.agent.once('debugger-input', () => { + clearTimeout(timer) + finished = true + done() + }) - // Perform HTTP request to try and trigger the probe - t.axios.get(t.breakpoint.url).catch((err) => { - // If the request hasn't fully completed by the time the tests ends and the target app is destroyed, Axios - // will complain with a "socket hang up" error. Hence this sanity check before calling `done(err)`. If we - // later add more tests below this one, this shouuldn't be an issue. - if (!finished) done(err) - }) - } + // Perform HTTP request to try and trigger the probe + t.axios.get(t.breakpoint.url).catch((err) => { + // If the request hasn't fully completed by the time the tests ends and the target app is destroyed, + // Axios will complain with a "socket hang up" error. Hence this sanity check before calling + // `done(err)`. If we later add more tests below this one, this shouuldn't be an issue. + if (!finished) done(err) + }) + } + }) }) t.agent.addRemoteConfig(t.rcConfig) @@ -467,7 +478,9 @@ function testBasicInputWithDD (t, done) { t.triggerBreakpoint() t.agent.on('message', ({ payload }) => { - const span = payload.find((arr) => arr[0].name === 'fastify.request')[0] + const span = payload.find((arr) => arr[0].name === 'fastify.request')?.[0] + if (!span) return + traceId = span.trace_id.toString() spanId = span.span_id.toString() @@ -477,6 +490,7 @@ function testBasicInputWithDD (t, done) { t.agent.on('debugger-input', ({ payload }) => { assertBasicInputPayload(t, payload) + payload = payload[0] assert.isObject(payload.dd) assert.hasAllKeys(payload.dd, ['trace_id', 'span_id']) assert.typeOf(payload.dd.trace_id, 'string') @@ -503,7 +517,7 @@ function testBasicInputWithoutDD (t, done) { t.agent.on('debugger-input', ({ payload }) => { assertBasicInputPayload(t, payload) - assert.doesNotHaveAnyKeys(payload, ['dd']) + assert.doesNotHaveAnyKeys(payload[0], ['dd']) done() }) @@ -511,6 +525,10 @@ function testBasicInputWithoutDD (t, done) { } function assertBasicInputPayload (t, payload) { + assert.isArray(payload) + assert.lengthOf(payload, 1) + payload = payload[0] + const expected = { ddsource: 'dd_debugger', hostname: os.hostname(), diff --git a/integration-tests/debugger/snapshot-pruning.spec.js b/integration-tests/debugger/snapshot-pruning.spec.js index c1ba218dd1c..b94d6afcce3 100644 --- a/integration-tests/debugger/snapshot-pruning.spec.js +++ b/integration-tests/debugger/snapshot-pruning.spec.js @@ -11,7 +11,7 @@ describe('Dynamic Instrumentation', function () { beforeEach(t.triggerBreakpoint) it('should prune snapshot if payload is too large', function (done) { - t.agent.on('debugger-input', ({ payload }) => { + t.agent.on('debugger-input', ({ payload: [payload] }) => { assert.isBelow(Buffer.byteLength(JSON.stringify(payload)), 1024 * 1024) // 1MB assert.deepEqual(payload['debugger.snapshot'].captures, { lines: { diff --git a/integration-tests/debugger/snapshot.spec.js b/integration-tests/debugger/snapshot.spec.js index e2f9d9eb047..68b42c97d35 100644 --- a/integration-tests/debugger/snapshot.spec.js +++ b/integration-tests/debugger/snapshot.spec.js @@ -11,7 +11,7 @@ describe('Dynamic Instrumentation', function () { beforeEach(t.triggerBreakpoint) it('should capture a snapshot', function (done) { - t.agent.on('debugger-input', ({ payload: { 'debugger.snapshot': { captures } } }) => { + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { assert.deepEqual(Object.keys(captures), ['lines']) assert.deepEqual(Object.keys(captures.lines), [String(t.breakpoint.line)]) @@ -114,7 +114,7 @@ describe('Dynamic Instrumentation', function () { }) it('should respect maxReferenceDepth', function (done) { - t.agent.on('debugger-input', ({ payload: { 'debugger.snapshot': { captures } } }) => { + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { const { locals } = captures.lines[t.breakpoint.line] delete locals.request delete locals.fastify @@ -150,7 +150,7 @@ describe('Dynamic Instrumentation', function () { }) it('should respect maxLength', function (done) { - t.agent.on('debugger-input', ({ payload: { 'debugger.snapshot': { captures } } }) => { + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { const { locals } = captures.lines[t.breakpoint.line] assert.deepEqual(locals.lstr, { @@ -167,7 +167,7 @@ describe('Dynamic Instrumentation', function () { }) it('should respect maxCollectionSize', function (done) { - t.agent.on('debugger-input', ({ payload: { 'debugger.snapshot': { captures } } }) => { + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { const { locals } = captures.lines[t.breakpoint.line] assert.deepEqual(locals.arr, { @@ -205,7 +205,7 @@ describe('Dynamic Instrumentation', function () { } } - t.agent.on('debugger-input', ({ payload: { 'debugger.snapshot': { captures } } }) => { + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { const { locals } = captures.lines[t.breakpoint.line] assert.deepEqual(Object.keys(locals), [ diff --git a/integration-tests/debugger/utils.js b/integration-tests/debugger/utils.js index 4f215723816..9f5175d84fc 100644 --- a/integration-tests/debugger/utils.js +++ b/integration-tests/debugger/utils.js @@ -50,9 +50,11 @@ function setup ({ env, testApp } = {}) { function triggerBreakpoint (url) { // Trigger the breakpoint once probe is successfully installed t.agent.on('debugger-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') { - t.axios.get(url) - } + payload.forEach((event) => { + if (event.debugger.diagnostics.status === 'INSTALLED') { + t.axios.get(url) + } + }) }) } diff --git a/packages/dd-trace/src/debugger/devtools_client/config.js b/packages/dd-trace/src/debugger/devtools_client/config.js index 7783bc84d75..950d8938872 100644 --- a/packages/dd-trace/src/debugger/devtools_client/config.js +++ b/packages/dd-trace/src/debugger/devtools_client/config.js @@ -9,7 +9,8 @@ const config = module.exports = { service: parentConfig.service, commitSHA: parentConfig.commitSHA, repositoryUrl: parentConfig.repositoryUrl, - parentThreadId + parentThreadId, + maxTotalPayloadSize: 5 * 1024 * 1024 // 5MB } updateUrl(parentConfig) diff --git a/packages/dd-trace/src/debugger/devtools_client/index.js b/packages/dd-trace/src/debugger/devtools_client/index.js index df158b7d2da..89c96db18c6 100644 --- a/packages/dd-trace/src/debugger/devtools_client/index.js +++ b/packages/dd-trace/src/debugger/devtools_client/index.js @@ -129,9 +129,8 @@ session.on('Debugger.paused', async ({ params }) => { } // TODO: Process template (DEBUG-2628) - send(probe.template, logger, dd, snapshot, (err) => { - if (err) log.error('Debugger error', err) - else ackEmitting(probe) + send(probe.template, logger, dd, snapshot, () => { + ackEmitting(probe) }) } }) diff --git a/packages/dd-trace/src/debugger/devtools_client/json-buffer.js b/packages/dd-trace/src/debugger/devtools_client/json-buffer.js new file mode 100644 index 00000000000..5010aafac3d --- /dev/null +++ b/packages/dd-trace/src/debugger/devtools_client/json-buffer.js @@ -0,0 +1,36 @@ +'use strict' + +class JSONBuffer { + constructor ({ size, timeout, onFlush }) { + this._maxSize = size + this._timeout = timeout + this._onFlush = onFlush + this._reset() + } + + _reset () { + clearTimeout(this._timer) + this._timer = null + this._partialJson = null + } + + _flush () { + const json = `${this._partialJson}]` + this._reset() + this._onFlush(json) + } + + write (str, size = Buffer.byteLength(str)) { + if (this._timer === null) { + this._partialJson = `[${str}` + this._timer = setTimeout(() => this._flush(), this._timeout) + } else if (Buffer.byteLength(this._partialJson) + size + 2 > this._maxSize) { + this._flush() + this.write(str, size) + } else { + this._partialJson += `,${str}` + } + } +} + +module.exports = JSONBuffer diff --git a/packages/dd-trace/src/debugger/devtools_client/send.js b/packages/dd-trace/src/debugger/devtools_client/send.js index 375afd7d47a..12d9b8cad84 100644 --- a/packages/dd-trace/src/debugger/devtools_client/send.js +++ b/packages/dd-trace/src/debugger/devtools_client/send.js @@ -4,13 +4,15 @@ const { hostname: getHostname } = require('os') const { stringify } = require('querystring') const config = require('./config') +const JSONBuffer = require('./json-buffer') const request = require('../../exporters/common/request') const { GIT_COMMIT_SHA, GIT_REPOSITORY_URL } = require('../../plugins/util/tags') +const log = require('../../log') const { version } = require('../../../../../package.json') module.exports = send -const MAX_PAYLOAD_SIZE = 1024 * 1024 // 1MB +const MAX_LOG_PAYLOAD_SIZE = 1024 * 1024 // 1MB const ddsource = 'dd_debugger' const hostname = getHostname() @@ -27,14 +29,10 @@ const ddtags = [ const path = `/debugger/v1/input?${stringify({ ddtags })}` -function send (message, logger, dd, snapshot, cb) { - const opts = { - method: 'POST', - url: config.url, - path, - headers: { 'Content-Type': 'application/json; charset=utf-8' } - } +let callbacks = [] +const jsonBuffer = new JSONBuffer({ size: config.maxTotalPayloadSize, timeout: 1000, onFlush }) +function send (message, logger, dd, snapshot, cb) { const payload = { ddsource, hostname, @@ -46,8 +44,9 @@ function send (message, logger, dd, snapshot, cb) { } let json = JSON.stringify(payload) + let size = Buffer.byteLength(json) - if (Buffer.byteLength(json) > MAX_PAYLOAD_SIZE) { + if (size > MAX_LOG_PAYLOAD_SIZE) { // TODO: This is a very crude way to handle large payloads. Proper pruning will be implemented later (DEBUG-2624) const line = Object.values(payload['debugger.snapshot'].captures.lines)[0] line.locals = { @@ -55,7 +54,26 @@ function send (message, logger, dd, snapshot, cb) { size: Object.keys(line.locals).length } json = JSON.stringify(payload) + size = Buffer.byteLength(json) + } + + jsonBuffer.write(json, size) + callbacks.push(cb) +} + +function onFlush (payload) { + const opts = { + method: 'POST', + url: config.url, + path, + headers: { 'Content-Type': 'application/json; charset=utf-8' } } - request(json, opts, cb) + const _callbacks = callbacks + callbacks = [] + + request(payload, opts, (err) => { + if (err) log.error('Could not send debugger payload', err) + else _callbacks.forEach(cb => cb()) + }) } diff --git a/packages/dd-trace/src/debugger/devtools_client/status.js b/packages/dd-trace/src/debugger/devtools_client/status.js index b228d7e50b7..7a7db799e53 100644 --- a/packages/dd-trace/src/debugger/devtools_client/status.js +++ b/packages/dd-trace/src/debugger/devtools_client/status.js @@ -2,6 +2,7 @@ const LRUCache = require('lru-cache') const config = require('./config') +const JSONBuffer = require('./json-buffer') const request = require('../../exporters/common/request') const FormData = require('../../exporters/common/form-data') const log = require('../../log') @@ -25,6 +26,8 @@ const cache = new LRUCache({ ttlAutopurge: true }) +const jsonBuffer = new JSONBuffer({ size: config.maxTotalPayloadSize, timeout: 1000, onFlush }) + const STATUSES = { RECEIVED: 'RECEIVED', INSTALLED: 'INSTALLED', @@ -71,11 +74,15 @@ function ackError (err, { id: probeId, version }) { } function send (payload) { + jsonBuffer.write(JSON.stringify(payload)) +} + +function onFlush (payload) { const form = new FormData() form.append( 'event', - JSON.stringify(payload), + payload, { filename: 'event.json', contentType: 'application/json; charset=utf-8' } ) @@ -87,7 +94,7 @@ function send (payload) { } request(form, options, (err) => { - if (err) log.error('[debugger:devtools_client] Error sending debugger payload', err) + if (err) log.error('[debugger:devtools_client] Error sending probe payload', err) }) } diff --git a/packages/dd-trace/test/debugger/devtools_client/json-buffer.spec.js b/packages/dd-trace/test/debugger/devtools_client/json-buffer.spec.js new file mode 100644 index 00000000000..34312f808dd --- /dev/null +++ b/packages/dd-trace/test/debugger/devtools_client/json-buffer.spec.js @@ -0,0 +1,45 @@ +'use strict' + +require('../../setup/mocha') + +const JSONBuffer = require('../../../src/debugger/devtools_client/json-buffer') + +const MAX_SAFE_SIGNED_INTEGER = 2 ** 31 - 1 + +describe('JSONBuffer', () => { + it('should call onFlush with the expected payload when the timeout is reached', function (done) { + const onFlush = (json) => { + const diff = Date.now() - start + expect(json).to.equal('[{"message":1},{"message":2},{"message":3}]') + expect(diff).to.be.within(95, 110) + done() + } + + const jsonBuffer = new JSONBuffer({ size: Infinity, timeout: 100, onFlush }) + + const start = Date.now() + jsonBuffer.write(JSON.stringify({ message: 1 })) + jsonBuffer.write(JSON.stringify({ message: 2 })) + jsonBuffer.write(JSON.stringify({ message: 3 })) + }) + + it('should call onFlush with the expected payload when the size is reached', function (done) { + const expectedPayloads = [ + '[{"message":1},{"message":2}]', + '[{"message":3},{"message":4}]' + ] + + const onFlush = (json) => { + expect(json).to.equal(expectedPayloads.shift()) + if (expectedPayloads.length === 0) done() + } + + const jsonBuffer = new JSONBuffer({ size: 30, timeout: MAX_SAFE_SIGNED_INTEGER, onFlush }) + + jsonBuffer.write(JSON.stringify({ message: 1 })) // size: 15 + jsonBuffer.write(JSON.stringify({ message: 2 })) // size: 29 + jsonBuffer.write(JSON.stringify({ message: 3 })) // size: 15 (flushed, and re-added) + jsonBuffer.write(JSON.stringify({ message: 4 })) // size: 29 + jsonBuffer.write(JSON.stringify({ message: 5 })) // size: 15 (flushed, and re-added) + }) +}) diff --git a/packages/dd-trace/test/debugger/devtools_client/send.spec.js b/packages/dd-trace/test/debugger/devtools_client/send.spec.js new file mode 100644 index 00000000000..ea4551d8ff6 --- /dev/null +++ b/packages/dd-trace/test/debugger/devtools_client/send.spec.js @@ -0,0 +1,111 @@ +'use strict' + +require('../../setup/mocha') + +const { hostname: getHostname } = require('os') +const { expectWithin, getRequestOptions } = require('./utils') +const JSONBuffer = require('../../../src/debugger/devtools_client/json-buffer') +const { version } = require('../../../../../package.json') + +process.env.DD_ENV = 'my-env' +process.env.DD_VERSION = 'my-version' +const service = 'my-service' +const commitSHA = 'my-commit-sha' +const repositoryUrl = 'my-repository-url' +const url = 'my-url' +const ddsource = 'dd_debugger' +const hostname = getHostname() +const message = { message: true } +const logger = { logger: true } +const dd = { dd: true } +const snapshot = { snapshot: true } + +describe('input message http requests', function () { + let send, request, jsonBuffer + + beforeEach(function () { + request = sinon.spy() + request['@noCallThru'] = true + + class JSONBufferSpy extends JSONBuffer { + constructor (...args) { + super(...args) + jsonBuffer = this + sinon.spy(this, 'write') + } + } + + send = proxyquire('../src/debugger/devtools_client/send', { + './config': { service, commitSHA, repositoryUrl, url, '@noCallThru': true }, + './json-buffer': JSONBufferSpy, + '../../exporters/common/request': request + }) + }) + + it('should buffer instead of calling request directly', function () { + const callback = sinon.spy() + + send(message, logger, dd, snapshot, callback) + expect(request).to.not.have.been.called + expect(jsonBuffer.write).to.have.been.calledOnceWith( + JSON.stringify(getPayload()) + ) + expect(callback).to.not.have.been.called + }) + + it('should call request with the expected payload once the buffer is flushed', function (done) { + const callback1 = sinon.spy() + const callback2 = sinon.spy() + const callback3 = sinon.spy() + + send({ message: 1 }, logger, dd, snapshot, callback1) + send({ message: 2 }, logger, dd, snapshot, callback2) + send({ message: 3 }, logger, dd, snapshot, callback3) + expect(request).to.not.have.been.called + + expectWithin(1200, () => { + expect(request).to.have.been.calledOnceWith(JSON.stringify([ + getPayload({ message: 1 }), + getPayload({ message: 2 }), + getPayload({ message: 3 }) + ])) + + const opts = getRequestOptions(request) + expect(opts).to.have.property('method', 'POST') + expect(opts).to.have.property( + 'path', + '/debugger/v1/input?ddtags=' + + `env%3A${process.env.DD_ENV}%2C` + + `version%3A${process.env.DD_VERSION}%2C` + + `debugger_version%3A${version}%2C` + + `host_name%3A${hostname}%2C` + + `git.commit.sha%3A${commitSHA}%2C` + + `git.repository_url%3A${repositoryUrl}` + ) + + expect(callback1).to.not.have.been.calledOnce + expect(callback2).to.not.have.been.calledOnce + expect(callback3).to.not.have.been.calledOnce + + request.firstCall.callback() + + expect(callback1).to.have.been.calledOnce + expect(callback2).to.have.been.calledOnce + expect(callback3).to.have.been.calledOnce + + done() + }) + }) +}) + +function getPayload (_message = message) { + return { + ddsource, + hostname, + service, + message: _message, + logger, + dd, + 'debugger.snapshot': snapshot + } +} diff --git a/packages/dd-trace/test/debugger/devtools_client/status.spec.js b/packages/dd-trace/test/debugger/devtools_client/status.spec.js index 365d86d6e96..88edde917e3 100644 --- a/packages/dd-trace/test/debugger/devtools_client/status.spec.js +++ b/packages/dd-trace/test/debugger/devtools_client/status.spec.js @@ -2,12 +2,15 @@ require('../../setup/mocha') +const { expectWithin, getRequestOptions } = require('./utils') +const JSONBuffer = require('../../../src/debugger/devtools_client/json-buffer') + const ddsource = 'dd_debugger' const service = 'my-service' const runtimeId = 'my-runtime-id' -describe('diagnostic message http request caching', function () { - let statusproxy, request +describe('diagnostic message http requests', function () { + let statusproxy, request, jsonBuffer const acks = [ ['ackReceived', 'RECEIVED'], @@ -20,8 +23,17 @@ describe('diagnostic message http request caching', function () { request = sinon.spy() request['@noCallThru'] = true + class JSONBufferSpy extends JSONBuffer { + constructor (...args) { + super(...args) + jsonBuffer = this + sinon.spy(this, 'write') + } + } + statusproxy = proxyquire('../src/debugger/devtools_client/status', { './config': { service, runtimeId, '@noCallThru': true }, + './json-buffer': JSONBufferSpy, '../../exporters/common/request': request }) }) @@ -45,54 +57,85 @@ describe('diagnostic message http request caching', function () { } }) - it('should only call once if no change', function () { + it('should buffer instead of calling request directly', function () { + ackFn({ id: 'foo', version: 0 }) + expect(request).to.not.have.been.called + expect(jsonBuffer.write).to.have.been.calledOnceWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'foo', version: 0, status, exception })) + ) + }) + + it('should only add to buffer once if no change', function () { ackFn({ id: 'foo', version: 0 }) - expect(request).to.have.been.calledOnce - assertRequestData(request, { probeId: 'foo', version: 0, status, exception }) + expect(jsonBuffer.write).to.have.been.calledOnceWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'foo', version: 0, status, exception })) + ) ackFn({ id: 'foo', version: 0 }) - expect(request).to.have.been.calledOnce + expect(jsonBuffer.write).to.have.been.calledOnce }) - it('should call again if version changes', function () { + it('should add to buffer again if version changes', function () { ackFn({ id: 'foo', version: 0 }) - expect(request).to.have.been.calledOnce - assertRequestData(request, { probeId: 'foo', version: 0, status, exception }) + expect(jsonBuffer.write).to.have.been.calledOnceWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'foo', version: 0, status, exception })) + ) ackFn({ id: 'foo', version: 1 }) - expect(request).to.have.been.calledTwice - assertRequestData(request, { probeId: 'foo', version: 1, status, exception }) + expect(jsonBuffer.write).to.have.been.calledTwice + expect(jsonBuffer.write.lastCall).to.have.been.calledWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'foo', version: 1, status, exception })) + ) }) - it('should call again if probeId changes', function () { + it('should add to buffer again if probeId changes', function () { ackFn({ id: 'foo', version: 0 }) - expect(request).to.have.been.calledOnce - assertRequestData(request, { probeId: 'foo', version: 0, status, exception }) + expect(jsonBuffer.write).to.have.been.calledOnceWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'foo', version: 0, status, exception })) + ) ackFn({ id: 'bar', version: 0 }) - expect(request).to.have.been.calledTwice - assertRequestData(request, { probeId: 'bar', version: 0, status, exception }) + expect(jsonBuffer.write).to.have.been.calledTwice + expect(jsonBuffer.write.lastCall).to.have.been.calledWith( + JSON.stringify(formatAsDiagnosticsEvent({ probeId: 'bar', version: 0, status, exception })) + ) + }) + + it('should call request with the expected payload once the buffer is flushed', function (done) { + ackFn({ id: 'foo', version: 0 }) + ackFn({ id: 'foo', version: 1 }) + ackFn({ id: 'bar', version: 0 }) + expect(request).to.not.have.been.called + + expectWithin(1200, () => { + expect(request).to.have.been.calledOnce + + const payload = getFormPayload(request) + + expect(payload).to.deep.equal([ + formatAsDiagnosticsEvent({ probeId: 'foo', version: 0, status, exception }), + formatAsDiagnosticsEvent({ probeId: 'foo', version: 1, status, exception }), + formatAsDiagnosticsEvent({ probeId: 'bar', version: 0, status, exception }) + ]) + + const opts = getRequestOptions(request) + expect(opts).to.have.property('method', 'POST') + expect(opts).to.have.property('path', '/debugger/v1/diagnostics') + + done() + }) }) }) } }) -function assertRequestData (request, { probeId, version, status, exception }) { - const payload = getFormPayload(request) +function formatAsDiagnosticsEvent ({ probeId, version, status, exception }) { const diagnostics = { probeId, runtimeId, probeVersion: version, status } // Error requests will also contain an `exception` property if (exception) diagnostics.exception = exception - expect(payload).to.deep.equal({ ddsource, service, debugger: { diagnostics } }) - - const opts = getRequestOptions(request) - expect(opts).to.have.property('method', 'POST') - expect(opts).to.have.property('path', '/debugger/v1/diagnostics') -} - -function getRequestOptions (request) { - return request.lastCall.args[1] + return { ddsource, service, debugger: { diagnostics } } } function getFormPayload (request) { diff --git a/packages/dd-trace/test/debugger/devtools_client/utils.js b/packages/dd-trace/test/debugger/devtools_client/utils.js index e15d567a7c1..2da3216cea1 100644 --- a/packages/dd-trace/test/debugger/devtools_client/utils.js +++ b/packages/dd-trace/test/debugger/devtools_client/utils.js @@ -3,7 +3,21 @@ const { randomUUID } = require('node:crypto') module.exports = { - generateProbeConfig + expectWithin, + generateProbeConfig, + getRequestOptions +} + +function expectWithin (timeout, fn, start = Date.now(), backoff = 1) { + try { + fn() + } catch (e) { + if (Date.now() - start > timeout) { + throw e + } else { + setTimeout(expectWithin, backoff, timeout, fn, start, backoff < 128 ? backoff * 2 : backoff) + } + } } function generateProbeConfig (breakpoint, overrides = {}) { @@ -23,3 +37,7 @@ function generateProbeConfig (breakpoint, overrides = {}) { ...overrides } } + +function getRequestOptions (request) { + return request.lastCall.args[1] +} From 7378bff1907990f661a0dc059569890582b4628b Mon Sep 17 00:00:00 2001 From: Thomas Watson Date: Tue, 7 Jan 2025 14:18:39 +0100 Subject: [PATCH 2/8] Benchmarks: No need to guard against unhandled promise rejections (#5025) --- benchmark/sirun/run-all-variants.js | 28 +++++++++++----------------- benchmark/sirun/run-one-variant.js | 10 +--------- 2 files changed, 12 insertions(+), 26 deletions(-) diff --git a/benchmark/sirun/run-all-variants.js b/benchmark/sirun/run-all-variants.js index 60f6a65992d..85894690354 100755 --- a/benchmark/sirun/run-all-variants.js +++ b/benchmark/sirun/run-all-variants.js @@ -14,25 +14,19 @@ const metaJson = require(path.join(process.cwd(), 'meta.json')) const env = Object.assign({}, process.env, { DD_TRACE_STARTUP_LOGS: 'false' }) ;(async () => { - try { - if (metaJson.variants) { - const variants = metaJson.variants - for (const variant in variants) { - const variantEnv = Object.assign({}, env, { SIRUN_VARIANT: variant }) - await exec('sirun', ['meta-temp.json'], { env: variantEnv, stdio: getStdio() }) - } - } else { - await exec('sirun', ['meta-temp.json'], { env, stdio: getStdio() }) + if (metaJson.variants) { + const variants = metaJson.variants + for (const variant in variants) { + const variantEnv = Object.assign({}, env, { SIRUN_VARIANT: variant }) + await exec('sirun', ['meta-temp.json'], { env: variantEnv, stdio: getStdio() }) } + } else { + await exec('sirun', ['meta-temp.json'], { env, stdio: getStdio() }) + } - try { - fs.unlinkSync(path.join(process.cwd(), 'meta-temp.json')) - } catch (e) { - // it's ok if we can't delete a temp file - } + try { + fs.unlinkSync(path.join(process.cwd(), 'meta-temp.json')) } catch (e) { - setImmediate(() => { - throw e // Older Node versions don't fail on uncaught promise rejections. - }) + // it's ok if we can't delete a temp file } })() diff --git a/benchmark/sirun/run-one-variant.js b/benchmark/sirun/run-one-variant.js index 77bb147c9e7..982c303ceae 100755 --- a/benchmark/sirun/run-one-variant.js +++ b/benchmark/sirun/run-one-variant.js @@ -8,12 +8,4 @@ process.env.DD_INSTRUMENTATION_TELEMETRY_ENABLED = 'false' const env = Object.assign({}, process.env, { DD_TRACE_STARTUP_LOGS: 'false' }) -;(async () => { - try { - await exec('sirun', ['meta-temp.json'], { env, stdio: getStdio() }) - } catch (e) { - setImmediate(() => { - throw e // Older Node versions don't fail on uncaught promise rejections. - }) - } -})() +exec('sirun', ['meta-temp.json'], { env, stdio: getStdio() }) From 317c7a9e096257c0f6d518d397a39dfb07e477cd Mon Sep 17 00:00:00 2001 From: simon-id Date: Tue, 7 Jan 2025 15:19:12 +0100 Subject: [PATCH 3/8] rename Tracer to NoopProxy in noop/proxy.js (#5068) --- packages/dd-trace/src/noop/proxy.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/dd-trace/src/noop/proxy.js b/packages/dd-trace/src/noop/proxy.js index ec8671a371e..5ab209e612c 100644 --- a/packages/dd-trace/src/noop/proxy.js +++ b/packages/dd-trace/src/noop/proxy.js @@ -10,7 +10,7 @@ const noopAppsec = new NoopAppsecSdk() const noopDogStatsDClient = new NoopDogStatsDClient() const noopLLMObs = new NoopLLMObsSDK(noop) -class Tracer { +class NoopProxy { constructor () { this._tracer = noop this.appsec = noopAppsec @@ -91,4 +91,4 @@ class Tracer { } } -module.exports = Tracer +module.exports = NoopProxy From daf7030eb7e0e02ca0a81c8ff7bd3fd018660381 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Tue, 7 Jan 2025 12:03:59 -0500 Subject: [PATCH 4/8] add trace level logging when updating config (#5071) --- packages/dd-trace/src/telemetry/index.js | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/dd-trace/src/telemetry/index.js b/packages/dd-trace/src/telemetry/index.js index eb1fe376c67..9328186a82a 100644 --- a/packages/dd-trace/src/telemetry/index.js +++ b/packages/dd-trace/src/telemetry/index.js @@ -307,6 +307,8 @@ function updateConfig (changes, config) { if (!config.telemetry.enabled) return if (changes.length === 0) return + logger.trace(changes) + const application = createAppObject(config) const host = createHostObject() From c7648a7b8f30051f10d8057c474465763c702bb0 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Tue, 7 Jan 2025 12:04:30 -0500 Subject: [PATCH 5/8] fix trace log level not adding parameters to output (#5069) --- packages/dd-trace/src/log/index.js | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/packages/dd-trace/src/log/index.js b/packages/dd-trace/src/log/index.js index 3fb9afff6fa..8968a15f60b 100644 --- a/packages/dd-trace/src/log/index.js +++ b/packages/dd-trace/src/log/index.js @@ -63,15 +63,17 @@ const log = { Error.captureStackTrace(logRecord, this.trace) - const fn = logRecord.stack.split('\n')[1].replace(/^\s+at ([^\s]+) .+/, '$1') + const stack = logRecord.stack.split('\n') + const fn = stack[1].replace(/^\s+at ([^\s]+) .+/, '$1') const params = args.map(a => { return a && a.hasOwnProperty('toString') && typeof a.toString === 'function' ? a.toString() : inspect(a, { depth: 3, breakLength: Infinity, compact: true }) }).join(', ') - const formatted = logRecord.stack.replace('Error: ', `Trace: ${fn}(${params})`) - traceChannel.publish(Log.parse(formatted)) + stack[0] = `Trace: ${fn}(${params})` + + traceChannel.publish(Log.parse(stack.join('\n'))) } return this }, From 34b751db6de148d2af8f4a116f53c3adf4381ad5 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Tue, 7 Jan 2025 23:21:41 -0500 Subject: [PATCH 6/8] improve logging of spans in trace log level (#5074) --- packages/datadog-core/src/storage.js | 13 +++++++++++-- packages/dd-trace/src/log/index.js | 7 ++----- packages/dd-trace/src/noop/span.js | 2 +- packages/dd-trace/src/opentracing/span.js | 12 +++++++++++- packages/dd-trace/src/opentracing/span_context.js | 12 ++++++++++++ packages/dd-trace/src/scope.js | 2 +- packages/dd-trace/test/log.spec.js | 12 ++++++++---- 7 files changed, 46 insertions(+), 14 deletions(-) diff --git a/packages/datadog-core/src/storage.js b/packages/datadog-core/src/storage.js index 15c9fff239c..fb5d889e555 100644 --- a/packages/datadog-core/src/storage.js +++ b/packages/datadog-core/src/storage.js @@ -21,8 +21,16 @@ class DatadogStorage { this._storage.exit(callback, ...args) } - getStore () { - const handle = this._storage.getStore() + // TODO: Refactor the Scope class to use a span-only store and remove this. + getHandle () { + return this._storage.getStore() + } + + getStore (handle) { + if (!handle) { + handle = this._storage.getStore() + } + return stores.get(handle) } @@ -50,6 +58,7 @@ const storage = function (namespace) { storage.disable = legacyStorage.disable.bind(legacyStorage) storage.enterWith = legacyStorage.enterWith.bind(legacyStorage) storage.exit = legacyStorage.exit.bind(legacyStorage) +storage.getHandle = legacyStorage.getHandle.bind(legacyStorage) storage.getStore = legacyStorage.getStore.bind(legacyStorage) storage.run = legacyStorage.run.bind(legacyStorage) diff --git a/packages/dd-trace/src/log/index.js b/packages/dd-trace/src/log/index.js index 8968a15f60b..db3a475e120 100644 --- a/packages/dd-trace/src/log/index.js +++ b/packages/dd-trace/src/log/index.js @@ -65,11 +65,8 @@ const log = { const stack = logRecord.stack.split('\n') const fn = stack[1].replace(/^\s+at ([^\s]+) .+/, '$1') - const params = args.map(a => { - return a && a.hasOwnProperty('toString') && typeof a.toString === 'function' - ? a.toString() - : inspect(a, { depth: 3, breakLength: Infinity, compact: true }) - }).join(', ') + const options = { depth: 2, breakLength: Infinity, compact: true, maxArrayLength: Infinity } + const params = args.map(a => inspect(a, options)).join(', ') stack[0] = `Trace: ${fn}(${params})` diff --git a/packages/dd-trace/src/noop/span.js b/packages/dd-trace/src/noop/span.js index 1a431d090ea..554fe7423ba 100644 --- a/packages/dd-trace/src/noop/span.js +++ b/packages/dd-trace/src/noop/span.js @@ -6,7 +6,7 @@ const { storage } = require('../../../datadog-core') // TODO: noop storage? class NoopSpan { constructor (tracer, parent) { - this._store = storage.getStore() + this._store = storage.getHandle() this._noopTracer = tracer this._noopContext = this._createContext(parent) } diff --git a/packages/dd-trace/src/opentracing/span.js b/packages/dd-trace/src/opentracing/span.js index 23f885bbabd..2c464b2ed1a 100644 --- a/packages/dd-trace/src/opentracing/span.js +++ b/packages/dd-trace/src/opentracing/span.js @@ -14,6 +14,7 @@ const { storage } = require('../../../datadog-core') const telemetryMetrics = require('../telemetry/metrics') const { channel } = require('dc-polyfill') const spanleak = require('../spanleak') +const util = require('util') const tracerMetrics = telemetryMetrics.manager.namespace('tracers') @@ -64,7 +65,7 @@ class DatadogSpan { this._debug = debug this._processor = processor this._prioritySampler = prioritySampler - this._store = storage.getStore() + this._store = storage.getHandle() this._duration = undefined this._events = [] @@ -105,6 +106,15 @@ class DatadogSpan { } } + [util.inspect.custom] () { + return { + ...this, + _parentTracer: `[${this._parentTracer.constructor.name}]`, + _prioritySampler: `[${this._prioritySampler.constructor.name}]`, + _processor: `[${this._processor.constructor.name}]` + } + } + toString () { const spanContext = this.context() const resourceName = spanContext._tags['resource.name'] || '' diff --git a/packages/dd-trace/src/opentracing/span_context.js b/packages/dd-trace/src/opentracing/span_context.js index 223348bfd55..1cdfeea1ae8 100644 --- a/packages/dd-trace/src/opentracing/span_context.js +++ b/packages/dd-trace/src/opentracing/span_context.js @@ -1,5 +1,6 @@ 'use strict' +const util = require('util') const { AUTO_KEEP } = require('../../../../ext/priority') // the lowercase, hex encoded upper 64 bits of a 128-bit trace id, if present @@ -31,6 +32,17 @@ class DatadogSpanContext { this._otelSpanContext = undefined } + [util.inspect.custom] () { + return { + ...this, + _trace: { + ...this._trace, + started: '[Array]', + finished: '[Array]' + } + } + } + toTraceId (get128bitId = false) { if (get128bitId) { return this._traceId.toBuffer().length <= 8 && this._trace.tags[TRACE_ID_128] diff --git a/packages/dd-trace/src/scope.js b/packages/dd-trace/src/scope.js index fb279ae0266..9b96ff565ea 100644 --- a/packages/dd-trace/src/scope.js +++ b/packages/dd-trace/src/scope.js @@ -17,7 +17,7 @@ class Scope { if (typeof callback !== 'function') return callback const oldStore = storage.getStore() - const newStore = span ? span._store : oldStore + const newStore = span ? storage.getStore(span._store) : oldStore storage.enterWith({ ...newStore, span }) diff --git a/packages/dd-trace/test/log.spec.js b/packages/dd-trace/test/log.spec.js index 16682f97db8..cbe5679414b 100644 --- a/packages/dd-trace/test/log.spec.js +++ b/packages/dd-trace/test/log.spec.js @@ -147,14 +147,18 @@ describe('log', () => { }) it('should log to console after setting log level to trace', function foo () { + class Foo { + constructor () { + this.bar = 'baz' + } + } + log.toggle(true, 'trace') - log.trace('argument', { hello: 'world' }, { - toString: () => 'string' - }, { foo: 'bar' }) + log.trace('argument', { hello: 'world' }, new Foo()) expect(console.debug).to.have.been.calledOnce expect(console.debug.firstCall.args[0]).to.match( - /^Trace: Test.foo\('argument', { hello: 'world' }, string, { foo: 'bar' }\)/ + /^Trace: Test.foo\('argument', { hello: 'world' }, Foo { bar: 'baz' }\)/ ) expect(console.debug.firstCall.args[0].split('\n').length).to.be.gte(3) }) From e2bee271f33e88cfbfd23ab19cc20ff576dbcc89 Mon Sep 17 00:00:00 2001 From: Thomas Watson Date: Wed, 8 Jan 2025 06:06:17 +0100 Subject: [PATCH 7/8] Copy config_norm_rules.json from dd-go (#5073) This is needed in order for CI to validate the following upcoming new config options: - `dynamicInstrumentationRedactedIdentifiers` - `dynamicInstrumentationRedactionExcludedIdentifiers` --- .../dd-trace/test/fixtures/telemetry/config_norm_rules.json | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/packages/dd-trace/test/fixtures/telemetry/config_norm_rules.json b/packages/dd-trace/test/fixtures/telemetry/config_norm_rules.json index d4014e8b839..c7a2941be88 100644 --- a/packages/dd-trace/test/fixtures/telemetry/config_norm_rules.json +++ b/packages/dd-trace/test/fixtures/telemetry/config_norm_rules.json @@ -112,6 +112,7 @@ "DD_IAST_DB_ROWS_TO_TAINT": "iast_db_rows_to_taint", "DD_IAST_DEDUPLICATION_ENABLED": "iast_deduplication_enabled", "DD_IAST_ENABLED": "iast_enabled", + "DD_IAST_EXPERIMENTAL_PROPAGATION_ENABLED": "iast_experimental_propagation_enabled", "DD_IAST_MAX_CONCURRENT_REQUESTS": "iast_max_concurrent_requests", "DD_IAST_MAX_RANGE_COUNT": "iast_max_range_count", "DD_IAST_REDACTION_ENABLED": "iast_redaction_enabled", @@ -306,6 +307,7 @@ "appsec.obfuscatorKeyRegex": "appsec_obfuscation_parameter_key_regexp", "appsec.obfuscatorValueRegex": "appsec_obfuscation_parameter_value_regexp", "appsec.rasp.enabled": "appsec_rasp_enabled", + "appsec.rasp_enabled": "appsec_rasp_enabled", "appsec.rateLimit": "appsec_rate_limit", "appsec.rules": "appsec_rules", "appsec.rules.metadata.rules_version": "appsec_rules_metadata_rules_version", @@ -452,6 +454,8 @@ "dynamic.instrumentation.enabled": "dynamic_instrumentation_enabled", "dynamic.instrumentation.metrics.enabled": "dynamic_instrumentation_metrics_enabled", "dynamicInstrumentationEnabled": "dynamic_instrumentation_enabled", + "dynamicInstrumentationRedactedIdentifiers": "dynamic_instrumentation_redacted_identifiers", + "dynamicInstrumentationRedactionExcludedIdentifiers": "dynamic_instrumentation_redaction_excluded_indentifiers", "dynamic_instrumentation.enabled": "dynamic_instrumentation_enabled", "dynamic_instrumentation.redacted_identifiers": "dynamic_instrumentation_redacted_identifiers", "dynamic_instrumentation.redacted_types": "dynamic_instrumentation_redacted_types", @@ -491,6 +495,7 @@ "iast.deduplication.enabled": "iast_deduplication_enabled", "iast.deduplicationEnabled": "iast_deduplication_enabled", "iast.enabled": "iast_enabled", + "iast.experimental.propagation.enabled": "iast_experimental_propagation_enabled", "iast.max-concurrent-requests": "iast_max_concurrent_requests", "iast.maxConcurrentRequests": "iast_max_concurrent_requests", "iast.maxContextOperations": "iast_max_context_operations", @@ -707,6 +712,7 @@ "trace.jmxfetch.kafka.enabled": "trace_jmxfetch_kafka_enabled", "trace.jmxfetch.tomcat.enabled": "trace_jmxfetch_tomcat_enabled", "trace.kafka.client.propagation.enabled": "trace_kafka_client_propagation_enabled", + "trace.kafka_distributed_tracing": "trace_kafka_distributed_tracing", "trace.laravel_queue_distributed_tracing": "trace_laravel_queue_distributed_tracing", "trace.log_file": "trace_log_file", "trace.log_level": "trace_log_level", From b36ce05a16d045b9dc0830cd851555f3176aa879 Mon Sep 17 00:00:00 2001 From: Thomas Watson Date: Wed, 8 Jan 2025 10:32:06 +0100 Subject: [PATCH 8/8] [DI] Implement PII redaction (#5053) The algorithm will look for: - names of variables - names of object properties - names of keys in maps The names will be matched against a disallow-list and if a match is found, its value will be redacted. The list is hardcoded and can be found here: packages/dd-trace/src/debugger/devtools_client/snapshot/redaction.js It's possible to add names to the list using the following environment variable: DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS Or it's possible to remove names from the list using the following environment variable: DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS Each environment variable takes a list of names separated by commas. Support for redacting instances of specific classes is not included in this commit. --- integration-tests/debugger/redact.spec.js | 49 ++++++++ .../debugger/target-app/redact.js | 26 ++++ .../dynamic-instrumentation/index.js | 24 +++- packages/dd-trace/src/config.js | 36 ++++++ .../src/debugger/devtools_client/config.js | 2 + .../devtools_client/snapshot/processor.js | 36 +++++- .../devtools_client/snapshot/redaction.js | 116 ++++++++++++++++++ packages/dd-trace/src/debugger/index.js | 15 +-- packages/dd-trace/src/proxy.js | 2 +- ...sibility-dynamic-instrumentation-script.js | 3 +- packages/dd-trace/test/config.spec.js | 22 ++++ .../snapshot/redaction.spec.js | 90 ++++++++++++++ .../snapshot/target-code/redaction.js | 35 ++++++ .../devtools_client/snapshot/utils.js | 17 ++- 14 files changed, 449 insertions(+), 24 deletions(-) create mode 100644 integration-tests/debugger/redact.spec.js create mode 100644 integration-tests/debugger/target-app/redact.js create mode 100644 packages/dd-trace/src/debugger/devtools_client/snapshot/redaction.js create mode 100644 packages/dd-trace/test/debugger/devtools_client/snapshot/redaction.spec.js create mode 100644 packages/dd-trace/test/debugger/devtools_client/snapshot/target-code/redaction.js diff --git a/integration-tests/debugger/redact.spec.js b/integration-tests/debugger/redact.spec.js new file mode 100644 index 00000000000..62a948b80a8 --- /dev/null +++ b/integration-tests/debugger/redact.spec.js @@ -0,0 +1,49 @@ +'use strict' + +const { assert } = require('chai') +const { setup } = require('./utils') + +// Default settings is tested in unit tests, so we only need to test the env vars here +describe('Dynamic Instrumentation snapshot PII redaction', function () { + describe('DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS=foo,bar', function () { + const t = setup({ env: { DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS: 'foo,bar' } }) + + it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', function (done) { + t.triggerBreakpoint() + + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { + const { locals } = captures.lines[t.breakpoint.line] + + assert.deepPropertyVal(locals, 'foo', { type: 'string', notCapturedReason: 'redactedIdent' }) + assert.deepPropertyVal(locals, 'bar', { type: 'string', notCapturedReason: 'redactedIdent' }) + assert.deepPropertyVal(locals, 'baz', { type: 'string', value: 'c' }) + + // existing redaction should not be impacted + assert.deepPropertyVal(locals, 'secret', { type: 'string', notCapturedReason: 'redactedIdent' }) + + done() + }) + + t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true })) + }) + }) + + describe('DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS=secret', function () { + const t = setup({ env: { DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS: 'secret' } }) + + it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', function (done) { + t.triggerBreakpoint() + + t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => { + const { locals } = captures.lines[t.breakpoint.line] + + assert.deepPropertyVal(locals, 'secret', { type: 'string', value: 'shh!' }) + assert.deepPropertyVal(locals, 'password', { type: 'string', notCapturedReason: 'redactedIdent' }) + + done() + }) + + t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true })) + }) + }) +}) diff --git a/integration-tests/debugger/target-app/redact.js b/integration-tests/debugger/target-app/redact.js new file mode 100644 index 00000000000..3ac7b51953c --- /dev/null +++ b/integration-tests/debugger/target-app/redact.js @@ -0,0 +1,26 @@ +'use strict' + +require('dd-trace/init') +const Fastify = require('fastify') + +const fastify = Fastify() + +fastify.get('/', function () { + /* eslint-disable no-unused-vars */ + const foo = 'a' + const bar = 'b' + const baz = 'c' + const secret = 'shh!' + const password = 'shh!' + /* eslint-enable no-unused-vars */ + + return { hello: 'world' } // BREAKPOINT: / +}) + +fastify.listen({ port: process.env.APP_PORT }, (err) => { + if (err) { + fastify.log.error(err) + process.exit(1) + } + process.send({ port: process.env.APP_PORT }) +}) diff --git a/packages/dd-trace/src/ci-visibility/dynamic-instrumentation/index.js b/packages/dd-trace/src/ci-visibility/dynamic-instrumentation/index.js index ec6e2a1fd75..8cf52e709f6 100644 --- a/packages/dd-trace/src/ci-visibility/dynamic-instrumentation/index.js +++ b/packages/dd-trace/src/ci-visibility/dynamic-instrumentation/index.js @@ -1,7 +1,7 @@ 'use strict' const { join } = require('path') -const { Worker } = require('worker_threads') +const { Worker, threadId: parentThreadId } = require('worker_threads') const { randomUUID } = require('crypto') const log = require('../../log') @@ -46,29 +46,47 @@ class TestVisDynamicInstrumentation { return this._readyPromise } - start () { + start (config) { if (this.worker) return const { NODE_OPTIONS, ...envWithoutNodeOptions } = process.env log.debug('Starting Test Visibility - Dynamic Instrumentation client...') + const rcChannel = new MessageChannel() // mock channel + const configChannel = new MessageChannel() // mock channel + this.worker = new Worker( join(__dirname, 'worker', 'index.js'), { execArgv: [], env: envWithoutNodeOptions, workerData: { + config: config.serialize(), + parentThreadId, + rcPort: rcChannel.port1, + configPort: configChannel.port1, breakpointSetChannel: this.breakpointSetChannel.port1, breakpointHitChannel: this.breakpointHitChannel.port1 }, - transferList: [this.breakpointSetChannel.port1, this.breakpointHitChannel.port1] + transferList: [ + rcChannel.port1, + configChannel.port1, + this.breakpointSetChannel.port1, + this.breakpointHitChannel.port1 + ] } ) this.worker.on('online', () => { log.debug('Test Visibility - Dynamic Instrumentation client is ready') this._onReady() }) + this.worker.on('error', (err) => { + log.error('Test Visibility - Dynamic Instrumentation worker error', err) + }) + this.worker.on('messageerror', (err) => { + log.error('Test Visibility - Dynamic Instrumentation worker messageerror', err) + }) // Allow the parent to exit even if the worker is still running this.worker.unref() diff --git a/packages/dd-trace/src/config.js b/packages/dd-trace/src/config.js index a16df70ee07..09ce9d5fd66 100644 --- a/packages/dd-trace/src/config.js +++ b/packages/dd-trace/src/config.js @@ -473,6 +473,8 @@ class Config { this._setValue(defaults, 'dogstatsd.port', '8125') this._setValue(defaults, 'dsmEnabled', false) this._setValue(defaults, 'dynamicInstrumentationEnabled', false) + this._setValue(defaults, 'dynamicInstrumentationRedactedIdentifiers', []) + this._setValue(defaults, 'dynamicInstrumentationRedactionExcludedIdentifiers', []) this._setValue(defaults, 'env', undefined) this._setValue(defaults, 'experimental.enableGetRumData', false) this._setValue(defaults, 'experimental.exporter', undefined) @@ -600,6 +602,8 @@ class Config { DD_DOGSTATSD_HOST, DD_DOGSTATSD_PORT, DD_DYNAMIC_INSTRUMENTATION_ENABLED, + DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS, + DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS, DD_ENV, DD_EXPERIMENTAL_API_SECURITY_ENABLED, DD_EXPERIMENTAL_APPSEC_STANDALONE_ENABLED, @@ -747,6 +751,12 @@ class Config { this._setString(env, 'dogstatsd.port', DD_DOGSTATSD_PORT) this._setBoolean(env, 'dsmEnabled', DD_DATA_STREAMS_ENABLED) this._setBoolean(env, 'dynamicInstrumentationEnabled', DD_DYNAMIC_INSTRUMENTATION_ENABLED) + this._setArray(env, 'dynamicInstrumentationRedactedIdentifiers', DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS) + this._setArray( + env, + 'dynamicInstrumentationRedactionExcludedIdentifiers', + DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS + ) this._setString(env, 'env', DD_ENV || tags.env) this._setBoolean(env, 'traceEnabled', DD_TRACE_ENABLED) this._setBoolean(env, 'experimental.enableGetRumData', DD_TRACE_EXPERIMENTAL_GET_RUM_DATA_ENABLED) @@ -927,6 +937,16 @@ class Config { } this._setBoolean(opts, 'dsmEnabled', options.dsmEnabled) this._setBoolean(opts, 'dynamicInstrumentationEnabled', options.experimental?.dynamicInstrumentationEnabled) + this._setArray( + opts, + 'dynamicInstrumentationRedactedIdentifiers', + options.experimental?.dynamicInstrumentationRedactedIdentifiers + ) + this._setArray( + opts, + 'dynamicInstrumentationRedactionExcludedIdentifiers', + options.experimental?.dynamicInstrumentationRedactionExcludedIdentifiers + ) this._setString(opts, 'env', options.env || tags.env) this._setBoolean(opts, 'experimental.enableGetRumData', options.experimental?.enableGetRumData) this._setString(opts, 'experimental.exporter', options.experimental?.exporter) @@ -1312,6 +1332,22 @@ class Config { this.sampler.sampleRate = this.sampleRate updateConfig(changes, this) } + + // TODO: Refactor the Config class so it never produces any config objects that are incompatible with MessageChannel + /** + * Serializes the config object so it can be passed over a Worker Thread MessageChannel. + * @returns {Object} The serialized config object. + */ + serialize () { + // URL objects cannot be serialized over the MessageChannel, so we need to convert them to strings first + if (this.url instanceof URL) { + const config = { ...this } + config.url = this.url.toString() + return config + } + + return this + } } function maybeInt (number) { diff --git a/packages/dd-trace/src/debugger/devtools_client/config.js b/packages/dd-trace/src/debugger/devtools_client/config.js index 950d8938872..4880bbe5fdb 100644 --- a/packages/dd-trace/src/debugger/devtools_client/config.js +++ b/packages/dd-trace/src/debugger/devtools_client/config.js @@ -5,6 +5,8 @@ const { format } = require('node:url') const log = require('../../log') const config = module.exports = { + dynamicInstrumentationRedactedIdentifiers: parentConfig.dynamicInstrumentationRedactedIdentifiers, + dynamicInstrumentationRedactionExcludedIdentifiers: parentConfig.dynamicInstrumentationRedactionExcludedIdentifiers, runtimeId: parentConfig.tags['runtime-id'], service: parentConfig.service, commitSHA: parentConfig.commitSHA, diff --git a/packages/dd-trace/src/debugger/devtools_client/snapshot/processor.js b/packages/dd-trace/src/debugger/devtools_client/snapshot/processor.js index ea52939ab0e..a7b14987987 100644 --- a/packages/dd-trace/src/debugger/devtools_client/snapshot/processor.js +++ b/packages/dd-trace/src/debugger/devtools_client/snapshot/processor.js @@ -1,6 +1,7 @@ 'use strict' const { collectionSizeSym, fieldCountSym } = require('./symbols') +const { normalizeName, REDACTED_IDENTIFIERS } = require('./redaction') module.exports = { processRawState: processProperties @@ -24,7 +25,14 @@ function processProperties (props, maxLength) { return result } +// TODO: Improve performance of redaction algorithm. +// This algorithm is probably slower than if we embedded the redaction logic inside the functions below. +// That way we didn't have to traverse objects that will just be redacted anyway. function getPropertyValue (prop, maxLength) { + return redact(prop, getPropertyValueRaw(prop, maxLength)) +} + +function getPropertyValueRaw (prop, maxLength) { // Special case for getters and setters which does not have a value property if ('get' in prop) { const hasGet = prop.get.type !== 'undefined' @@ -185,8 +193,11 @@ function toMap (type, pairs, maxLength) { // `pair.value` is a special wrapper-object with subtype `internal#entry`. This can be skipped and we can go // directly to its children, of which there will always be exactly two, the first containing the key, and the // second containing the value of this entry of the Map. + const shouldRedact = shouldRedactMapValue(pair.value.properties[0]) const key = getPropertyValue(pair.value.properties[0], maxLength) - const val = getPropertyValue(pair.value.properties[1], maxLength) + const val = shouldRedact + ? notCapturedRedacted(pair.value.properties[1].value.type) + : getPropertyValue(pair.value.properties[1], maxLength) result.entries[i++] = [key, val] } @@ -240,6 +251,25 @@ function arrayBufferToString (bytes, size) { return buf.toString() } +function redact (prop, obj) { + const name = getNormalizedNameFromProp(prop) + return REDACTED_IDENTIFIERS.has(name) ? notCapturedRedacted(obj.type) : obj +} + +function shouldRedactMapValue (key) { + const isSymbol = key.value.type === 'symbol' + if (!isSymbol && key.value.type !== 'string') return false // WeakMaps uses objects as keys + const name = normalizeName( + isSymbol ? key.value.description : key.value.value, + isSymbol + ) + return REDACTED_IDENTIFIERS.has(name) +} + +function getNormalizedNameFromProp (prop) { + return normalizeName(prop.name, 'symbol' in prop) +} + function setNotCaptureReasonOnCollection (result, collection) { if (collectionSizeSym in collection) { result.notCapturedReason = 'collectionSize' @@ -250,3 +280,7 @@ function setNotCaptureReasonOnCollection (result, collection) { function notCapturedDepth (type) { return { type, notCapturedReason: 'depth' } } + +function notCapturedRedacted (type) { + return { type, notCapturedReason: 'redactedIdent' } +} diff --git a/packages/dd-trace/src/debugger/devtools_client/snapshot/redaction.js b/packages/dd-trace/src/debugger/devtools_client/snapshot/redaction.js new file mode 100644 index 00000000000..5ccb58f4053 --- /dev/null +++ b/packages/dd-trace/src/debugger/devtools_client/snapshot/redaction.js @@ -0,0 +1,116 @@ +'use strict' + +const config = require('../config') + +const excludedIdentifiers = config.dynamicInstrumentationRedactionExcludedIdentifiers.map((name) => normalizeName(name)) + +const REDACTED_IDENTIFIERS = new Set( + [ + '2fa', + '_csrf', + '_csrf_token', + '_session', + '_xsrf', + 'access_token', + 'address', + 'aiohttp_session', + 'api_key', + 'apisecret', + 'apisignature', + 'applicationkey', + 'appkey', + 'auth', + 'authtoken', + 'authorization', + 'cc_number', + 'certificatepin', + 'cipher', + 'client_secret', + 'clientid', + 'config', + 'connect.sid', + 'connectionstring', + 'cookie', + 'credentials', + 'creditcard', + 'csrf', + 'csrf_token', + 'cvv', + 'databaseurl', + 'db_url', + 'email', + 'encryption_key', + 'encryptionkeyid', + 'geo_location', + 'gpg_key', + 'ip_address', + 'jti', + 'jwt', + 'license_key', + 'masterkey', + 'mysql_pwd', + 'nonce', + 'oauth', + 'oauthtoken', + 'otp', + 'passhash', + 'passwd', + 'password', + 'passwordb', + 'pem_file', + 'pgp_key', + 'PHPSESSID', + 'phonenumber', + 'pin', + 'pincode', + 'pkcs8', + 'private_key', + 'publickey', + 'pwd', + 'recaptcha_key', + 'refresh_token', + 'remote_addr', + 'routingnumber', + 'salt', + 'secret', + 'secretKey', + 'securitycode', + 'security_answer', + 'security_question', + 'serviceaccountcredentials', + 'session', + 'sessionid', + 'sessionkey', + 'set_cookie', + 'signature', + 'signaturekey', + 'ssh_key', + 'ssn', + 'symfony', + 'token', + 'transactionid', + 'twilio_token', + 'user_session', + 'uuid', + 'voterid', + 'x-auth-token', + 'x_api_key', + 'x_csrftoken', + 'x_forwarded_for', + 'x_real_ip', + 'XSRF-TOKEN', + ...config.dynamicInstrumentationRedactedIdentifiers + ] + .map((name) => normalizeName(name)) + .filter((name) => excludedIdentifiers.includes(name) === false) +) + +function normalizeName (name, isSymbol) { + if (isSymbol) name = name.slice(7, -1) // Remove `Symbol(` and `)` + return name.toLowerCase().replace(/[-_@$.]/g, '') +} + +module.exports = { + REDACTED_IDENTIFIERS, + normalizeName +} diff --git a/packages/dd-trace/src/debugger/index.js b/packages/dd-trace/src/debugger/index.js index fee514f32f1..a1a94d9e321 100644 --- a/packages/dd-trace/src/debugger/index.js +++ b/packages/dd-trace/src/debugger/index.js @@ -48,7 +48,7 @@ function start (config, rc) { execArgv: [], // Avoid worker thread inheriting the `-r` command line argument env, // Avoid worker thread inheriting the `NODE_OPTIONS` environment variable (in case it contains `-r`) workerData: { - config: serializableConfig(config), + config: config.serialize(), parentThreadId, rcPort: rcChannel.port1, configPort: configChannel.port1 @@ -88,16 +88,5 @@ function start (config, rc) { function configure (config) { if (configChannel === null) return - configChannel.port2.postMessage(serializableConfig(config)) -} - -// TODO: Refactor the Config class so it never produces any config objects that are incompatible with MessageChannel -function serializableConfig (config) { - // URL objects cannot be serialized over the MessageChannel, so we need to convert them to strings first - if (config.url instanceof URL) { - config = { ...config } - config.url = config.url.toString() - } - - return config + configChannel.port2.postMessage(config.serialize()) } diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index fd814c9d6e3..874945eeecc 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -184,7 +184,7 @@ class Tracer extends NoopProxy { if (config.isTestDynamicInstrumentationEnabled) { const testVisibilityDynamicInstrumentation = require('./ci-visibility/dynamic-instrumentation') - testVisibilityDynamicInstrumentation.start() + testVisibilityDynamicInstrumentation.start(config) } } catch (e) { log.error('Error initialising tracer', e) diff --git a/packages/dd-trace/test/ci-visibility/dynamic-instrumentation/target-app/test-visibility-dynamic-instrumentation-script.js b/packages/dd-trace/test/ci-visibility/dynamic-instrumentation/target-app/test-visibility-dynamic-instrumentation-script.js index fedfaefdc6c..39382ea0089 100644 --- a/packages/dd-trace/test/ci-visibility/dynamic-instrumentation/target-app/test-visibility-dynamic-instrumentation-script.js +++ b/packages/dd-trace/test/ci-visibility/dynamic-instrumentation/target-app/test-visibility-dynamic-instrumentation-script.js @@ -3,11 +3,12 @@ const path = require('path') const tvDynamicInstrumentation = require('../../../../src/ci-visibility/dynamic-instrumentation') const sum = require('./di-dependency') +const Config = require('../../../../src/config') // keep process alive const intervalId = setInterval(() => {}, 5000) -tvDynamicInstrumentation.start() +tvDynamicInstrumentation.start(new Config()) tvDynamicInstrumentation.isReady().then(() => { const [ diff --git a/packages/dd-trace/test/config.spec.js b/packages/dd-trace/test/config.spec.js index 8e87b6fa855..49e691afae8 100644 --- a/packages/dd-trace/test/config.spec.js +++ b/packages/dd-trace/test/config.spec.js @@ -232,6 +232,8 @@ describe('Config', () => { expect(config).to.have.property('logLevel', 'debug') expect(config).to.have.nested.property('codeOriginForSpans.enabled', false) expect(config).to.have.property('dynamicInstrumentationEnabled', false) + expect(config).to.have.deep.property('dynamicInstrumentationRedactedIdentifiers', []) + expect(config).to.have.deep.property('dynamicInstrumentationRedactionExcludedIdentifiers', []) expect(config).to.have.property('traceId128BitGenerationEnabled', true) expect(config).to.have.property('traceId128BitLoggingEnabled', false) expect(config).to.have.property('spanAttributeSchema', 'v0') @@ -314,6 +316,8 @@ describe('Config', () => { { name: 'dogstatsd.port', value: '8125', origin: 'default' }, { name: 'dsmEnabled', value: false, origin: 'default' }, { name: 'dynamicInstrumentationEnabled', value: false, origin: 'default' }, + { name: 'dynamicInstrumentationRedactedIdentifiers', value: [], origin: 'default' }, + { name: 'dynamicInstrumentationRedactionExcludedIdentifiers', value: [], origin: 'default' }, { name: 'env', value: undefined, origin: 'default' }, { name: 'experimental.enableGetRumData', value: false, origin: 'default' }, { name: 'experimental.exporter', value: undefined, origin: 'default' }, @@ -457,6 +461,8 @@ describe('Config', () => { process.env.DD_TRACE_REPORT_HOSTNAME = 'true' process.env.DD_ENV = 'test' process.env.DD_DYNAMIC_INSTRUMENTATION_ENABLED = 'true' + process.env.DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS = 'foo,bar' + process.env.DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS = 'a,b,c' process.env.DD_TRACE_GLOBAL_TAGS = 'foo:bar,baz:qux' process.env.DD_TRACE_SAMPLE_RATE = '0.5' process.env.DD_TRACE_RATE_LIMIT = '-1' @@ -552,6 +558,8 @@ describe('Config', () => { expect(config).to.have.property('reportHostname', true) expect(config).to.have.nested.property('codeOriginForSpans.enabled', true) expect(config).to.have.property('dynamicInstrumentationEnabled', true) + expect(config).to.have.deep.property('dynamicInstrumentationRedactedIdentifiers', ['foo', 'bar']) + expect(config).to.have.deep.property('dynamicInstrumentationRedactionExcludedIdentifiers', ['a', 'b', 'c']) expect(config).to.have.property('env', 'test') expect(config).to.have.property('sampleRate', 0.5) expect(config).to.have.property('traceEnabled', true) @@ -656,6 +664,8 @@ describe('Config', () => { { name: 'dogstatsd.hostname', value: 'dsd-agent', origin: 'env_var' }, { name: 'dogstatsd.port', value: '5218', origin: 'env_var' }, { name: 'dynamicInstrumentationEnabled', value: true, origin: 'env_var' }, + { name: 'dynamicInstrumentationRedactedIdentifiers', value: ['foo', 'bar'], origin: 'env_var' }, + { name: 'dynamicInstrumentationRedactionExcludedIdentifiers', value: ['a', 'b', 'c'], origin: 'env_var' }, { name: 'env', value: 'test', origin: 'env_var' }, { name: 'experimental.enableGetRumData', value: true, origin: 'env_var' }, { name: 'experimental.exporter', value: 'log', origin: 'env_var' }, @@ -851,6 +861,8 @@ describe('Config', () => { experimental: { b3: true, dynamicInstrumentationEnabled: true, + dynamicInstrumentationRedactedIdentifiers: ['foo', 'bar'], + dynamicInstrumentationRedactionExcludedIdentifiers: ['a', 'b', 'c'], traceparent: true, runtimeId: true, exporter: 'log', @@ -896,6 +908,8 @@ describe('Config', () => { expect(config).to.have.property('service', 'service') expect(config).to.have.property('version', '0.1.0') expect(config).to.have.property('dynamicInstrumentationEnabled', true) + expect(config).to.have.deep.property('dynamicInstrumentationRedactedIdentifiers', ['foo', 'bar']) + expect(config).to.have.deep.property('dynamicInstrumentationRedactionExcludedIdentifiers', ['a', 'b', 'c']) expect(config).to.have.property('env', 'test') expect(config).to.have.property('sampleRate', 0.5) expect(config).to.have.property('logger', logger) @@ -974,6 +988,8 @@ describe('Config', () => { { name: 'dogstatsd.hostname', value: 'agent-dsd', origin: 'code' }, { name: 'dogstatsd.port', value: '5218', origin: 'code' }, { name: 'dynamicInstrumentationEnabled', value: true, origin: 'code' }, + { name: 'dynamicInstrumentationRedactedIdentifiers', value: ['foo', 'bar'], origin: 'code' }, + { name: 'dynamicInstrumentationRedactionExcludedIdentifiers', value: ['a', 'b', 'c'], origin: 'code' }, { name: 'env', value: 'test', origin: 'code' }, { name: 'experimental.enableGetRumData', value: true, origin: 'code' }, { name: 'experimental.exporter', value: 'log', origin: 'code' }, @@ -1175,6 +1191,8 @@ describe('Config', () => { process.env.DD_TRACE_REPORT_HOSTNAME = 'true' process.env.DD_ENV = 'test' process.env.DD_DYNAMIC_INSTRUMENTATION_ENABLED = 'true' + process.env.DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS = 'foo,bar' + process.env.DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS = 'a,b,c' process.env.DD_API_KEY = '123' process.env.DD_TRACE_SPAN_ATTRIBUTE_SCHEMA = 'v0' process.env.DD_TRACE_PEER_SERVICE_DEFAULTS_ENABLED = 'false' @@ -1253,6 +1271,8 @@ describe('Config', () => { experimental: { b3: false, dynamicInstrumentationEnabled: false, + dynamicInstrumentationRedactedIdentifiers: ['foo2', 'bar2'], + dynamicInstrumentationRedactionExcludedIdentifiers: ['a2', 'b2'], traceparent: false, runtimeId: false, exporter: 'agent', @@ -1318,6 +1338,8 @@ describe('Config', () => { expect(config).to.have.property('version', '1.0.0') expect(config).to.have.nested.property('codeOriginForSpans.enabled', false) expect(config).to.have.property('dynamicInstrumentationEnabled', false) + expect(config).to.have.deep.property('dynamicInstrumentationRedactedIdentifiers', ['foo2', 'bar2']) + expect(config).to.have.deep.property('dynamicInstrumentationRedactionExcludedIdentifiers', ['a2', 'b2']) expect(config).to.have.property('env', 'development') expect(config).to.have.property('clientIpEnabled', true) expect(config).to.have.property('clientIpHeader', 'x-true-client-ip') diff --git a/packages/dd-trace/test/debugger/devtools_client/snapshot/redaction.spec.js b/packages/dd-trace/test/debugger/devtools_client/snapshot/redaction.spec.js new file mode 100644 index 00000000000..cd1b4a959a8 --- /dev/null +++ b/packages/dd-trace/test/debugger/devtools_client/snapshot/redaction.spec.js @@ -0,0 +1,90 @@ +'use strict' + +require('../../../setup/mocha') + +const { expect } = require('chai') +const { getTargetCodePath, enable, teardown, assertOnBreakpoint, setAndTriggerBreakpoint } = require('./utils') + +const target = getTargetCodePath(__filename) +const BREAKPOINT_LINE_NUMBER = 32 + +describe('debugger -> devtools client -> snapshot.getLocalStateForCallFrame', function () { + describe('redaction', function () { + beforeEach(enable(__filename)) + + afterEach(teardown) + + // Non-default configuration is tested in the integration tests + it('should replace PII in keys/properties/variables with expected notCapturedReason', function (done) { + assertOnBreakpoint(done, (state) => { + expect(state).to.have.all.keys( + 'nonNormalizedSecretToken', 'foo', 'secret', 'Se_cret_$', 'weakMapKey', 'obj' + ) + + expect(state).to.have.deep.property('foo', { type: 'string', value: 'bar' }) + expect(state).to.have.deep.property('secret', { type: 'string', notCapturedReason: 'redactedIdent' }) + expect(state).to.have.deep.property('Se_cret_$', { type: 'string', notCapturedReason: 'redactedIdent' }) + expect(state).to.have.deep.property('weakMapKey', { + type: 'Object', + fields: { secret: { type: 'string', notCapturedReason: 'redactedIdent' } } + }) + expect(state).to.have.deep.property('obj') + expect(state.obj).to.have.property('type', 'Object') + + const { fields } = state.obj + expect(fields).to.have.all.keys( + 'foo', 'secret', '@Se-cret_$_', 'nested', 'arr', 'map', 'weakmap', 'password', + 'Symbol(secret)', 'Symbol(@Se-cret_$_)' + ) + + expect(fields).to.have.deep.property('foo', { type: 'string', value: 'bar' }) + expect(fields).to.have.deep.property('secret', { type: 'string', notCapturedReason: 'redactedIdent' }) + expect(fields).to.have.deep.property('@Se-cret_$_', { type: 'string', notCapturedReason: 'redactedIdent' }) + expect(fields).to.have.deep.property('nested', { + type: 'Object', + fields: { secret: { type: 'string', notCapturedReason: 'redactedIdent' } } + }) + expect(fields).to.have.deep.property('arr', { + type: 'Array', + elements: [{ type: 'Object', fields: { secret: { type: 'string', notCapturedReason: 'redactedIdent' } } }] + }) + expect(fields).to.have.deep.property('map', { + type: 'Map', + entries: [ + [ + { type: 'string', value: 'foo' }, + { type: 'string', value: 'bar' } + ], + [ + { type: 'string', value: 'secret' }, + { type: 'string', notCapturedReason: 'redactedIdent' } + ], + [ + { type: 'string', value: '@Se-cret_$.' }, + { type: 'string', notCapturedReason: 'redactedIdent' } + ], + [ + { type: 'symbol', value: 'Symbol(secret)' }, + { type: 'string', notCapturedReason: 'redactedIdent' } + ], + [ + { type: 'symbol', value: 'Symbol(@Se-cret_$.)' }, + { notCapturedReason: 'redactedIdent', type: 'string' } + ] + ] + }) + expect(fields).to.have.deep.property('weakmap', { + type: 'WeakMap', + entries: [[ + { type: 'Object', fields: { secret: { type: 'string', notCapturedReason: 'redactedIdent' } } }, + { type: 'number', value: '42' } + ]] + }) + expect(fields).to.have.deep.property('password', { type: 'string', notCapturedReason: 'redactedIdent' }) + expect(fields).to.have.deep.property('Symbol(secret)', { type: 'string', notCapturedReason: 'redactedIdent' }) + }) + + setAndTriggerBreakpoint(target, BREAKPOINT_LINE_NUMBER) + }) + }) +}) diff --git a/packages/dd-trace/test/debugger/devtools_client/snapshot/target-code/redaction.js b/packages/dd-trace/test/debugger/devtools_client/snapshot/target-code/redaction.js new file mode 100644 index 00000000000..45e76a23a9c --- /dev/null +++ b/packages/dd-trace/test/debugger/devtools_client/snapshot/target-code/redaction.js @@ -0,0 +1,35 @@ +'use strict' + +function run () { + const nonNormalizedSecretToken = '@Se-cret_$.' + const foo = 'bar' // eslint-disable-line no-unused-vars + const secret = 'shh!' + const Se_cret_$ = 'shh!' // eslint-disable-line camelcase, no-unused-vars + const weakMapKey = { secret: 'shh!' } + const obj = { + foo: 'bar', + secret, + [nonNormalizedSecretToken]: 'shh!', + nested: { secret: 'shh!' }, + arr: [{ secret: 'shh!' }], + map: new Map([ + ['foo', 'bar'], + ['secret', 'shh!'], + [nonNormalizedSecretToken, 'shh!'], + [Symbol('secret'), 'shh!'], + [Symbol(nonNormalizedSecretToken), 'shh!'] + ]), + weakmap: new WeakMap([[weakMapKey, 42]]), + [Symbol('secret')]: 'shh!', + [Symbol(nonNormalizedSecretToken)]: 'shh!' + } + + Object.defineProperty(obj, 'password', { + value: 'shh!', + enumerable: false + }) + + return obj // breakpoint at this line +} + +module.exports = { run } diff --git a/packages/dd-trace/test/debugger/devtools_client/snapshot/utils.js b/packages/dd-trace/test/debugger/devtools_client/snapshot/utils.js index 215b93a4002..22f7610205f 100644 --- a/packages/dd-trace/test/debugger/devtools_client/snapshot/utils.js +++ b/packages/dd-trace/test/debugger/devtools_client/snapshot/utils.js @@ -10,6 +10,13 @@ session['@noCallThru'] = true proxyquire('../src/debugger/devtools_client/snapshot/collector', { '../session': session }) +proxyquire('../src/debugger/devtools_client/snapshot/redaction', { + '../config': { + dynamicInstrumentationRedactedIdentifiers: [], + dynamicInstrumentationRedactionExcludedIdentifiers: [], + '@noCallThru': true + } +}) const { getLocalStateForCallFrame } = require('../../../../src/debugger/devtools_client/snapshot') @@ -75,16 +82,16 @@ async function setAndTriggerBreakpoint (path, line) { run() } -function assertOnBreakpoint (done, config, callback) { - if (typeof config === 'function') { - callback = config - config = undefined +function assertOnBreakpoint (done, snapshotConfig, callback) { + if (typeof snapshotConfig === 'function') { + callback = snapshotConfig + snapshotConfig = undefined } session.once('Debugger.paused', ({ params }) => { expect(params.hitBreakpoints.length).to.eq(1) - getLocalStateForCallFrame(params.callFrames[0], config).then((process) => { + getLocalStateForCallFrame(params.callFrames[0], snapshotConfig).then((process) => { callback(process()) done() }).catch(done)