diff --git a/integration-tests/debugger/basic.spec.js b/integration-tests/debugger/basic.spec.js index 6db68d0607d..4bb5d7b2fa6 100644 --- a/integration-tests/debugger/basic.spec.js +++ b/integration-tests/debugger/basic.spec.js @@ -9,514 +9,552 @@ const { ACKNOWLEDGED, ERROR } = require('../../packages/dd-trace/src/appsec/remo const { version } = require('../../package.json') describe('Dynamic Instrumentation', function () { - describe('DD_TRACING_ENABLED=true', function () { - testWithTracingEnabled() - }) - - describe('DD_TRACING_ENABLED=false', function () { - testWithTracingEnabled(false) - }) -}) - -function testWithTracingEnabled (tracingEnabled = true) { - const t = setup({ DD_TRACING_ENABLED: tracingEnabled }) + describe('Default env', function () { + const t = setup() - it('base case: target app should work as expected if no test probe has been added', async function () { - const response = await t.axios.get(t.breakpoint.url) - assert.strictEqual(response.status, 200) - assert.deepStrictEqual(response.data, { hello: 'bar' }) - }) + it('base case: target app should work as expected if no test probe has been added', async function () { + const response = await t.axios.get(t.breakpoint.url) + assert.strictEqual(response.status, 200) + assert.deepStrictEqual(response.data, { hello: 'bar' }) + }) - describe('diagnostics messages', function () { - it('should send expected diagnostics messages if probe is received and triggered', function (done) { - let receivedAckUpdate = false - const probeId = t.rcConfig.config.id - const expectedPayloads = [{ - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'EMITTING' } } - }] - - t.agent.on('remote-config-ack-update', (id, version, state, error) => { - assert.strictEqual(id, t.rcConfig.id) - assert.strictEqual(version, 1) - assert.strictEqual(state, ACKNOWLEDGED) - assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail - - receivedAckUpdate = true - endIfDone() - }) + describe('diagnostics messages', function () { + it('should send expected diagnostics messages if probe is received and triggered', function (done) { + let receivedAckUpdate = false + const probeId = t.rcConfig.config.id + const expectedPayloads = [{ + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'EMITTING' } } + }] - t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - assertUUID(payload.debugger.diagnostics.runtimeId) + t.agent.on('remote-config-ack-update', (id, version, state, error) => { + assert.strictEqual(id, t.rcConfig.id) + assert.strictEqual(version, 1) + assert.strictEqual(state, ACKNOWLEDGED) + assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail - 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 { + receivedAckUpdate = true endIfDone() - } - }) + }) - t.agent.addRemoteConfig(t.rcConfig) + 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() + } + }) - function endIfDone () { - if (receivedAckUpdate && expectedPayloads.length === 0) done() - } - }) + t.agent.addRemoteConfig(t.rcConfig) - it('should send expected diagnostics messages if probe is first received and then updated', function (done) { - let receivedAckUpdates = 0 - const probeId = t.rcConfig.config.id - const expectedPayloads = [{ - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 1, status: 'RECEIVED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 1, status: 'INSTALLED' } } - }] - const triggers = [ - () => { - t.rcConfig.config.version++ - t.agent.updateRemoteConfig(t.rcConfig.id, t.rcConfig.config) - }, - () => {} - ] - - t.agent.on('remote-config-ack-update', (id, version, state, error) => { - assert.strictEqual(id, t.rcConfig.id) - assert.strictEqual(version, ++receivedAckUpdates) - assert.strictEqual(state, ACKNOWLEDGED) - assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail - - endIfDone() + function endIfDone () { + if (receivedAckUpdate && expectedPayloads.length === 0) done() + } }) - 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() - }) + it('should send expected diagnostics messages if probe is first received and then updated', function (done) { + let receivedAckUpdates = 0 + const probeId = t.rcConfig.config.id + const expectedPayloads = [{ + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 1, status: 'RECEIVED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { probeId, probeVersion: 1, status: 'INSTALLED' } } + }] + const triggers = [ + () => { + t.rcConfig.config.version++ + t.agent.updateRemoteConfig(t.rcConfig.id, t.rcConfig.config) + }, + () => {} + ] - t.agent.addRemoteConfig(t.rcConfig) + t.agent.on('remote-config-ack-update', (id, version, state, error) => { + assert.strictEqual(id, t.rcConfig.id) + assert.strictEqual(version, ++receivedAckUpdates) + assert.strictEqual(state, ACKNOWLEDGED) + assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail - function endIfDone () { - if (receivedAckUpdates === 2 && expectedPayloads.length === 0) done() - } - }) + endIfDone() + }) - it('should send expected diagnostics messages if probe is first received and then deleted', function (done) { - let receivedAckUpdate = false - let payloadsProcessed = false - const probeId = t.rcConfig.config.id - const expectedPayloads = [{ - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } - }, { - ddsource: 'dd_debugger', - service: 'node', - debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } - }] - - t.agent.on('remote-config-ack-update', (id, version, state, error) => { - assert.strictEqual(id, t.rcConfig.id) - assert.strictEqual(version, 1) - assert.strictEqual(state, ACKNOWLEDGED) - assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail - - receivedAckUpdate = true - endIfDone() - }) + 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() + }) - t.agent.on('debugger-diagnostics', ({ payload }) => { - const expected = expectedPayloads.shift() - assertObjectContains(payload, expected) - assertUUID(payload.debugger.diagnostics.runtimeId) + t.agent.addRemoteConfig(t.rcConfig) - 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 + function endIfDone () { + if (receivedAckUpdates === 2 && expectedPayloads.length === 0) done() } }) - t.agent.addRemoteConfig(t.rcConfig) - - function endIfDone () { - if (receivedAckUpdate && payloadsProcessed) done() - } - }) - - const unsupporedOrInvalidProbes = [[ - 'should send expected error diagnostics messages if probe doesn\'t conform to expected schema', - 'bad config!!!', - { status: 'ERROR' } - ], [ - 'should send expected error diagnostics messages if probe type isn\'t supported', - t.generateProbeConfig({ type: 'INVALID_PROBE' }) - ], [ - 'should send expected error diagnostics messages if it isn\'t a line-probe', - t.generateProbeConfig({ where: { foo: 'bar' } }) // TODO: Use valid schema for method probe instead - ]] - - for (const [title, config, customErrorDiagnosticsObj] of unsupporedOrInvalidProbes) { - it(title, function (done) { + it('should send expected diagnostics messages if probe is first received and then deleted', function (done) { let receivedAckUpdate = false - - t.agent.on('remote-config-ack-update', (id, version, state, error) => { - assert.strictEqual(id, `logProbe_${config.id}`) - assert.strictEqual(version, 1) - assert.strictEqual(state, ERROR) - assert.strictEqual(error.slice(0, 6), 'Error:') - - receivedAckUpdate = true - endIfDone() - }) - - const probeId = config.id + let payloadsProcessed = false + const probeId = t.rcConfig.config.id const expectedPayloads = [{ ddsource: 'dd_debugger', service: 'node', - debugger: { diagnostics: { status: 'RECEIVED' } } + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'RECEIVED' } } }, { ddsource: 'dd_debugger', service: 'node', - debugger: { diagnostics: customErrorDiagnosticsObj ?? { probeId, probeVersion: 0, status: 'ERROR' } } + debugger: { diagnostics: { probeId, probeVersion: 0, status: 'INSTALLED' } } }] + t.agent.on('remote-config-ack-update', (id, version, state, error) => { + assert.strictEqual(id, t.rcConfig.id) + assert.strictEqual(version, 1) + assert.strictEqual(state, ACKNOWLEDGED) + assert.notOk(error) // falsy check since error will be an empty string, but that's an implementation detail + + receivedAckUpdate = true + endIfDone() + }) + 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') + 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 } - - endIfDone() }) - t.agent.addRemoteConfig({ - product: 'LIVE_DEBUGGING', - id: `logProbe_${config.id}`, - config - }) + t.agent.addRemoteConfig(t.rcConfig) function endIfDone () { - if (receivedAckUpdate && expectedPayloads.length === 0) done() + if (receivedAckUpdate && payloadsProcessed) done() } }) - } - }) - describe('input messages', function () { - it('should capture and send expected payload when a log line probe is triggered', function (done) { - let traceId, spanId, dd + const unsupporedOrInvalidProbes = [[ + 'should send expected error diagnostics messages if probe doesn\'t conform to expected schema', + 'bad config!!!', + { status: 'ERROR' } + ], [ + 'should send expected error diagnostics messages if probe type isn\'t supported', + t.generateProbeConfig({ type: 'INVALID_PROBE' }) + ], [ + 'should send expected error diagnostics messages if it isn\'t a line-probe', + t.generateProbeConfig({ where: { foo: 'bar' } }) // TODO: Use valid schema for method probe instead + ]] + + for (const [title, config, customErrorDiagnosticsObj] of unsupporedOrInvalidProbes) { + it(title, function (done) { + let receivedAckUpdate = false + + t.agent.on('remote-config-ack-update', (id, version, state, error) => { + assert.strictEqual(id, `logProbe_${config.id}`) + assert.strictEqual(version, 1) + assert.strictEqual(state, ERROR) + assert.strictEqual(error.slice(0, 6), 'Error:') + + receivedAckUpdate = true + endIfDone() + }) - t.triggerBreakpoint() + const probeId = config.id + const expectedPayloads = [{ + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: { status: 'RECEIVED' } } + }, { + ddsource: 'dd_debugger', + service: 'node', + debugger: { diagnostics: customErrorDiagnosticsObj ?? { probeId, probeVersion: 0, status: 'ERROR' } } + }] + + 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') + } - t.agent.on('message', ({ payload }) => { - const span = payload.find((arr) => arr[0].name === 'fastify.request')[0] - traceId = span.trace_id.toString() - spanId = span.span_id.toString() + endIfDone() + }) - assertDD() - }) + t.agent.addRemoteConfig({ + product: 'LIVE_DEBUGGING', + id: `logProbe_${config.id}`, + config + }) - t.agent.on('debugger-input', ({ payload }) => { - const expected = { - ddsource: 'dd_debugger', - hostname: os.hostname(), - service: 'node', - message: 'Hello World!', - logger: { - name: t.breakpoint.file, - method: 'fooHandler', - version, - thread_name: 'MainThread' - }, - 'debugger.snapshot': { - probe: { - id: t.rcConfig.config.id, - version: 0, - location: { file: t.breakpoint.file, lines: [String(t.breakpoint.line)] } - }, - language: 'javascript' + function endIfDone () { + if (receivedAckUpdate && expectedPayloads.length === 0) done() } - } + }) + } + }) + + describe('input messages', function () { + it( + 'should capture and send expected payload when a log line probe is triggered', + testBasicInputWithDD.bind(null, t) + ) - assertObjectContains(payload, expected) + it('should respond with updated message if probe message is updated', function (done) { + const expectedMessages = ['Hello World!', 'Hello Updated World!'] + const triggers = [ + async () => { + await t.axios.get(t.breakpoint.url) + t.rcConfig.config.version++ + t.rcConfig.config.template = 'Hello Updated World!' + t.agent.updateRemoteConfig(t.rcConfig.id, t.rcConfig.config) + }, + async () => { + await t.axios.get(t.breakpoint.url) + } + ] - assert.match(payload.logger.thread_id, /^pid:\d+$/) + t.agent.on('debugger-diagnostics', ({ payload }) => { + if (payload.debugger.diagnostics.status === 'INSTALLED') triggers.shift()().catch(done) + }) - if (tracingEnabled) { - assert.isObject(payload.dd) - assert.hasAllKeys(payload.dd, ['trace_id', 'span_id']) - assert.typeOf(payload.dd.trace_id, 'string') - assert.typeOf(payload.dd.span_id, 'string') - assert.isAbove(payload.dd.trace_id.length, 0) - assert.isAbove(payload.dd.span_id.length, 0) - dd = payload.dd - } else { - assert.doesNotHaveAnyKeys(payload, ['dd']) - } + t.agent.on('debugger-input', ({ payload }) => { + assert.strictEqual(payload.message, expectedMessages.shift()) + if (expectedMessages.length === 0) done() + }) - assertUUID(payload['debugger.snapshot'].id) - assert.isNumber(payload['debugger.snapshot'].timestamp) - assert.isTrue(payload['debugger.snapshot'].timestamp > Date.now() - 1000 * 60) - assert.isTrue(payload['debugger.snapshot'].timestamp <= Date.now()) - - assert.isArray(payload['debugger.snapshot'].stack) - assert.isAbove(payload['debugger.snapshot'].stack.length, 0) - for (const frame of payload['debugger.snapshot'].stack) { - assert.isObject(frame) - assert.hasAllKeys(frame, ['fileName', 'function', 'lineNumber', 'columnNumber']) - assert.isString(frame.fileName) - assert.isString(frame.function) - assert.isAbove(frame.lineNumber, 0) - assert.isAbove(frame.columnNumber, 0) - } - const topFrame = payload['debugger.snapshot'].stack[0] - // path seems to be prefeixed with `/private` on Mac - assert.match(topFrame.fileName, new RegExp(`${t.appFile}$`)) - assert.strictEqual(topFrame.function, 'fooHandler') - assert.strictEqual(topFrame.lineNumber, t.breakpoint.line) - assert.strictEqual(topFrame.columnNumber, 3) - - if (tracingEnabled) { - assertDD() - } else { - done() - } + t.agent.addRemoteConfig(t.rcConfig) }) - t.agent.addRemoteConfig(t.rcConfig) - - function assertDD () { - if (!traceId || !spanId || !dd) return - assert.strictEqual(dd.trace_id, traceId) - assert.strictEqual(dd.span_id, spanId) - done() - } - }) + 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 + }) - it('should respond with updated message if probe message is updated', function (done) { - const expectedMessages = ['Hello World!', 'Hello Updated World!'] - const triggers = [ - async () => { - await t.axios.get(t.breakpoint.url) - t.rcConfig.config.version++ - t.rcConfig.config.template = 'Hello Updated World!' - t.agent.updateRemoteConfig(t.rcConfig.id, t.rcConfig.config) - }, - async () => { - await t.axios.get(t.breakpoint.url) - } - ] + t.agent.removeRemoteConfig(t.rcConfig.id) + } + }) - t.agent.on('debugger-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') triggers.shift()().catch(done) - }) + t.agent.on('debugger-input', () => { + assert.fail('should not capture anything when the probe is deleted') + }) - t.agent.on('debugger-input', ({ payload }) => { - assert.strictEqual(payload.message, expectedMessages.shift()) - if (expectedMessages.length === 0) done() + t.agent.addRemoteConfig(t.rcConfig) }) - - t.agent.addRemoteConfig(t.rcConfig) }) - 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 - }) + describe('sampling', function () { + it('should respect sampling rate for single probe', function (done) { + let start, timer + let payloadsReceived = 0 + const rcConfig = t.generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) - t.agent.removeRemoteConfig(t.rcConfig.id) + function triggerBreakpointContinuously () { + t.axios.get(t.breakpoint.url).catch(done) + timer = setTimeout(triggerBreakpointContinuously, 10) } - }) - t.agent.on('debugger-input', () => { - assert.fail('should not capture anything when the probe is deleted') - }) + t.agent.on('debugger-diagnostics', ({ payload }) => { + if (payload.debugger.diagnostics.status === 'INSTALLED') triggerBreakpointContinuously() + }) - t.agent.addRemoteConfig(t.rcConfig) - }) - }) + t.agent.on('debugger-input', () => { + payloadsReceived++ + if (payloadsReceived === 1) { + start = Date.now() + } else if (payloadsReceived === 2) { + const duration = Date.now() - start + clearTimeout(timer) - describe('sampling', function () { - it('should respect sampling rate for single probe', function (done) { - let start, timer - let payloadsReceived = 0 - const rcConfig = t.generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) + // Allow for a variance of -5/+50ms (time will tell if this is enough) + assert.isAbove(duration, 995) + assert.isBelow(duration, 1050) - function triggerBreakpointContinuously () { - t.axios.get(t.breakpoint.url).catch(done) - timer = setTimeout(triggerBreakpointContinuously, 10) - } + // 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-diagnostics', ({ payload }) => { - if (payload.debugger.diagnostics.status === 'INSTALLED') triggerBreakpointContinuously() + t.agent.addRemoteConfig(rcConfig) }) - 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!')) + it('should adhere to individual probes sample rate', function (done) { + const rcConfig1 = t.breakpoints[0].generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) + 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) + } + } } - }) - t.agent.addRemoteConfig(rcConfig) - }) + t.agent.on('debugger-diagnostics', ({ payload }) => { + const { probeId, status } = payload.debugger.diagnostics + if (status === 'INSTALLED') state[probeId].tiggerBreakpointContinuously() + }) - it('should adhere to individual probes sample rate', function (done) { - const rcConfig1 = t.breakpoints[0].generateRemoteConfig({ sampling: { snapshotsPerSecond: 1 } }) - 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) + 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!')) } - } - } + }) - t.agent.on('debugger-diagnostics', ({ payload }) => { - const { probeId, status } = payload.debugger.diagnostics - if (status === 'INSTALLED') state[probeId].tiggerBreakpointContinuously() - }) + t.agent.addRemoteConfig(rcConfig1) + t.agent.addRemoteConfig(rcConfig2) - 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!')) + function doneWhenCalledTwice () { + if (doneWhenCalledTwice.calledOnce) return done() + doneWhenCalledTwice.calledOnce = true } }) + }) - t.agent.addRemoteConfig(rcConfig1) - t.agent.addRemoteConfig(rcConfig2) + describe('race conditions', 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() + }) - function doneWhenCalledTwice () { - if (doneWhenCalledTwice.calledOnce) return done() - doneWhenCalledTwice.calledOnce = true - } + // 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) + }) }) }) - describe('race conditions', 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() - }) + describe('DD_TRACING_ENABLED=true, DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED=true', function () { + const t = setup({ DD_TRACING_ENABLED: true, DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED: true }) - // 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) - }) - } - }) + describe('input messages', function () { + it( + 'should capture and send expected payload when a log line probe is triggered', + testBasicInputWithDD.bind(null, t) + ) + }) + }) - t.agent.addRemoteConfig(t.rcConfig) + describe('DD_TRACING_ENABLED=true, DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED=false', function () { + const t = setup({ DD_TRACING_ENABLED: true, DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED: false }) + + describe('input messages', function () { + it( + 'should capture and send expected payload when a log line probe is triggered', + testBasicInputWithDD.bind(null, t) + ) }) }) + + describe('DD_TRACING_ENABLED=false', function () { + const t = setup({ DD_TRACING_ENABLED: false }) + + describe('input messages', function () { + it( + 'should capture and send expected payload when a log line probe is triggered', + testBasicInputWithoutDD.bind(null, t) + ) + }) + }) +}) + +function testBasicInputWithDD (t, done) { + let traceId, spanId, dd + + t.triggerBreakpoint() + + t.agent.on('message', ({ payload }) => { + const span = payload.find((arr) => arr[0].name === 'fastify.request')[0] + traceId = span.trace_id.toString() + spanId = span.span_id.toString() + + assertDD() + }) + + t.agent.on('debugger-input', ({ payload }) => { + assertBasicInputPayload(t, payload) + + assert.isObject(payload.dd) + assert.hasAllKeys(payload.dd, ['trace_id', 'span_id']) + assert.typeOf(payload.dd.trace_id, 'string') + assert.typeOf(payload.dd.span_id, 'string') + assert.isAbove(payload.dd.trace_id.length, 0) + assert.isAbove(payload.dd.span_id.length, 0) + dd = payload.dd + + assertDD() + }) + + t.agent.addRemoteConfig(t.rcConfig) + + function assertDD () { + if (!traceId || !spanId || !dd) return + assert.strictEqual(dd.trace_id, traceId) + assert.strictEqual(dd.span_id, spanId) + done() + } +} + +function testBasicInputWithoutDD (t, done) { + t.triggerBreakpoint() + + t.agent.on('debugger-input', ({ payload }) => { + assertBasicInputPayload(t, payload) + assert.doesNotHaveAnyKeys(payload, ['dd']) + done() + }) + + t.agent.addRemoteConfig(t.rcConfig) +} + +function assertBasicInputPayload (t, payload) { + const expected = { + ddsource: 'dd_debugger', + hostname: os.hostname(), + service: 'node', + message: 'Hello World!', + logger: { + name: t.breakpoint.file, + method: 'fooHandler', + version, + thread_name: 'MainThread' + }, + 'debugger.snapshot': { + probe: { + id: t.rcConfig.config.id, + version: 0, + location: { file: t.breakpoint.file, lines: [String(t.breakpoint.line)] } + }, + language: 'javascript' + } + } + + assertObjectContains(payload, expected) + + assert.match(payload.logger.thread_id, /^pid:\d+$/) + + assertUUID(payload['debugger.snapshot'].id) + assert.isNumber(payload['debugger.snapshot'].timestamp) + assert.isTrue(payload['debugger.snapshot'].timestamp > Date.now() - 1000 * 60) + assert.isTrue(payload['debugger.snapshot'].timestamp <= Date.now()) + + assert.isArray(payload['debugger.snapshot'].stack) + assert.isAbove(payload['debugger.snapshot'].stack.length, 0) + for (const frame of payload['debugger.snapshot'].stack) { + assert.isObject(frame) + assert.hasAllKeys(frame, ['fileName', 'function', 'lineNumber', 'columnNumber']) + assert.isString(frame.fileName) + assert.isString(frame.function) + assert.isAbove(frame.lineNumber, 0) + assert.isAbove(frame.columnNumber, 0) + } + const topFrame = payload['debugger.snapshot'].stack[0] + // path seems to be prefeixed with `/private` on Mac + assert.match(topFrame.fileName, new RegExp(`${t.appFile}$`)) + assert.strictEqual(topFrame.function, 'fooHandler') + assert.strictEqual(topFrame.lineNumber, t.breakpoint.line) + assert.strictEqual(topFrame.columnNumber, 3) } diff --git a/integration-tests/profiler/fstest.js b/integration-tests/profiler/fstest.js new file mode 100644 index 00000000000..c65887c102e --- /dev/null +++ b/integration-tests/profiler/fstest.js @@ -0,0 +1,40 @@ +const fs = require('fs') +const os = require('os') +const path = require('path') + +const tracer = require('dd-trace').init() +tracer.profilerStarted().then(() => { + tracer.trace('x', (_, done) => { + setImmediate(() => { + // Generate 1MB of random data + const buffer = Buffer.alloc(1024 * 1024) + for (let i = 0; i < buffer.length; i++) { + buffer[i] = Math.floor(Math.random() * 256) + } + + // Create a temporary file + const tempFilePath = path.join(os.tmpdir(), 'tempfile.txt') + + fs.writeFile(tempFilePath, buffer, (err) => { + if (err) throw err + + // Read the data back + setImmediate(() => { + fs.readFile(tempFilePath, (err, readData) => { + setImmediate(() => { + // Delete the temporary file + fs.unlink(tempFilePath, (err) => { + if (err) throw err + }) + done() + }) + if (err) throw err + if (Buffer.compare(buffer, readData) !== 0) { + throw new Error('Data read from file is different from data written to file') + } + }) + }) + }) + }) + }) +}) diff --git a/integration-tests/profiler/profiler.spec.js b/integration-tests/profiler/profiler.spec.js index 80be4c8fd36..6c7f4942e1e 100644 --- a/integration-tests/profiler/profiler.spec.js +++ b/integration-tests/profiler/profiler.spec.js @@ -104,7 +104,108 @@ function expectTimeout (messagePromise, allowErrors = false) { ) } +class TimelineEventProcessor { + constructor (strings, encoded) { + this.strings = strings + this.encoded = encoded + } +} + +class NetworkEventProcessor extends TimelineEventProcessor { + constructor (strings, encoded) { + super(strings, encoded) + + this.hostKey = strings.dedup('host') + this.addressKey = strings.dedup('address') + this.portKey = strings.dedup('port') + } + + processLabel (label, processedLabels) { + switch (label.key) { + case this.hostKey: + processedLabels.host = label.str + return true + case this.addressKey: + processedLabels.address = label.str + return true + case this.portKey: + processedLabels.port = label.num + return true + default: + return false + } + } + + decorateEvent (ev, pl) { + // Exactly one of these is defined + assert.isTrue(!!pl.address !== !!pl.host, this.encoded) + if (pl.address) { + ev.address = this.strings.strings[pl.address] + } else { + ev.host = this.strings.strings[pl.host] + } + if (pl.port) { + ev.port = pl.port + } + } +} + async function gatherNetworkTimelineEvents (cwd, scriptFilePath, eventType, args) { + return gatherTimelineEvents(cwd, scriptFilePath, eventType, args, NetworkEventProcessor) +} + +class FilesystemEventProcessor extends TimelineEventProcessor { + constructor (strings, encoded) { + super(strings, encoded) + + this.fdKey = strings.dedup('fd') + this.fileKey = strings.dedup('file') + this.flagKey = strings.dedup('flag') + this.modeKey = strings.dedup('mode') + this.pathKey = strings.dedup('path') + } + + processLabel (label, processedLabels) { + switch (label.key) { + case this.fdKey: + processedLabels.fd = label.num + return true + case this.fileKey: + processedLabels.file = label.str + return true + case this.flagKey: + processedLabels.flag = label.str + return true + case this.modeKey: + processedLabels.mode = label.str + return true + case this.pathKey: + processedLabels.path = label.str + return true + default: + return false + } + } + + decorateEvent (ev, pl) { + ev.fd = pl.fd + ev.file = this.strings.strings[pl.file] + ev.flag = this.strings.strings[pl.flag] + ev.mode = this.strings.strings[pl.mode] + ev.path = this.strings.strings[pl.path] + for (const [k, v] of Object.entries(ev)) { + if (v === undefined) { + delete ev[k] + } + } + } +} + +async function gatherFilesystemTimelineEvents (cwd, scriptFilePath) { + return gatherTimelineEvents(cwd, scriptFilePath, 'fs', [], FilesystemEventProcessor) +} + +async function gatherTimelineEvents (cwd, scriptFilePath, eventType, args, Processor) { const procStart = BigInt(Date.now() * 1000000) const proc = fork(path.join(cwd, scriptFilePath), args, { cwd, @@ -123,36 +224,35 @@ async function gatherNetworkTimelineEvents (cwd, scriptFilePath, eventType, args const strings = profile.stringTable const tsKey = strings.dedup('end_timestamp_ns') const eventKey = strings.dedup('event') - const hostKey = strings.dedup('host') - const addressKey = strings.dedup('address') - const portKey = strings.dedup('port') - const nameKey = strings.dedup('operation') + const operationKey = strings.dedup('operation') const spanIdKey = strings.dedup('span id') const localRootSpanIdKey = strings.dedup('local root span id') const eventValue = strings.dedup(eventType) const events = [] + const processor = new Processor(strings, encoded) for (const sample of profile.sample) { - let ts, event, host, address, port, name, spanId, localRootSpanId + let ts, event, operation, spanId, localRootSpanId + const processedLabels = {} const unexpectedLabels = [] for (const label of sample.label) { switch (label.key) { case tsKey: ts = label.num; break - case nameKey: name = label.str; break + case operationKey: operation = label.str; break case eventKey: event = label.str; break - case hostKey: host = label.str; break - case addressKey: address = label.str; break - case portKey: port = label.num; break case spanIdKey: spanId = label.str; break case localRootSpanIdKey: localRootSpanId = label.str; break - default: unexpectedLabels.push(label.key) + default: + if (!processor.processLabel(label, processedLabels)) { + unexpectedLabels.push(label.key) + } } } - // Gather only DNS events; ignore sporadic GC events + // Timestamp must be defined and be between process start and end time + assert.isDefined(ts, encoded) + assert.isTrue(ts <= procEnd, encoded) + assert.isTrue(ts >= procStart, encoded) + // Gather only tested events if (event === eventValue) { - // Timestamp must be defined and be between process start and end time - assert.isDefined(ts, encoded) - assert.isTrue(ts <= procEnd, encoded) - assert.isTrue(ts >= procStart, encoded) if (process.platform !== 'win32') { assert.isDefined(spanId, encoded) assert.isDefined(localRootSpanId, encoded) @@ -160,23 +260,14 @@ async function gatherNetworkTimelineEvents (cwd, scriptFilePath, eventType, args assert.isUndefined(spanId, encoded) assert.isUndefined(localRootSpanId, encoded) } - assert.isDefined(name, encoded) + assert.isDefined(operation, encoded) if (unexpectedLabels.length > 0) { const labelsStr = JSON.stringify(unexpectedLabels) const labelsStrStr = unexpectedLabels.map(k => strings.strings[k]).join(',') assert.fail(`Unexpected labels: ${labelsStr}\n${labelsStrStr}\n${encoded}`) } - // Exactly one of these is defined - assert.isTrue(!!address !== !!host, encoded) - const ev = { name: strings.strings[name] } - if (address) { - ev.address = strings.strings[address] - } else { - ev.host = strings.strings[host] - } - if (port) { - ev.port = port - } + const ev = { operation: strings.strings[operation] } + processor.decorateEvent(ev, processedLabels) events.push(ev) } } @@ -323,14 +414,30 @@ describe('profiler', () => { assert.equal(endpoints.size, 3, encoded) }) + it('fs timeline events work', async () => { + const fsEvents = await gatherFilesystemTimelineEvents(cwd, 'profiler/fstest.js') + assert.equal(fsEvents.length, 6) + const path = fsEvents[0].path + const fd = fsEvents[1].fd + assert(path.endsWith('tempfile.txt')) + assert.sameDeepMembers(fsEvents, [ + { flag: 'w', mode: '', operation: 'open', path }, + { fd, operation: 'write' }, + { fd, operation: 'close' }, + { file: path, operation: 'writeFile' }, + { operation: 'readFile', path }, + { operation: 'unlink', path } + ]) + }) + it('dns timeline events work', async () => { const dnsEvents = await gatherNetworkTimelineEvents(cwd, 'profiler/dnstest.js', 'dns') assert.sameDeepMembers(dnsEvents, [ - { name: 'lookup', host: 'example.org' }, - { name: 'lookup', host: 'example.com' }, - { name: 'lookup', host: 'datadoghq.com' }, - { name: 'queryA', host: 'datadoghq.com' }, - { name: 'lookupService', address: '13.224.103.60', port: 80 } + { operation: 'lookup', host: 'example.org' }, + { operation: 'lookup', host: 'example.com' }, + { operation: 'lookup', host: 'datadoghq.com' }, + { operation: 'queryA', host: 'datadoghq.com' }, + { operation: 'lookupService', address: '13.224.103.60', port: 80 } ]) }) @@ -366,8 +473,8 @@ describe('profiler', () => { // The profiled program should have two TCP connection events to the two // servers. assert.sameDeepMembers(events, [ - { name: 'connect', host: '127.0.0.1', port: port1 }, - { name: 'connect', host: '127.0.0.1', port: port2 } + { operation: 'connect', host: '127.0.0.1', port: port1 }, + { operation: 'connect', host: '127.0.0.1', port: port2 } ]) } finally { server2.close() diff --git a/package.json b/package.json index 7b94a226d59..3cc7c893243 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "dd-trace", - "version": "4.53.0", + "version": "4.54.0", "description": "Datadog APM tracing client for JavaScript", "main": "index.js", "typings": "index.d.ts", diff --git a/packages/datadog-instrumentations/src/fs.js b/packages/datadog-instrumentations/src/fs.js index 9ae201b9860..894c1b6ef33 100644 --- a/packages/datadog-instrumentations/src/fs.js +++ b/packages/datadog-instrumentations/src/fs.js @@ -13,6 +13,9 @@ const errorChannel = channel('apm:fs:operation:error') const ddFhSym = Symbol('ddFileHandle') let kHandle, kDirReadPromisified, kDirClosePromisified +// Update packages/dd-trace/src/profiling/profilers/event_plugins/fs.js if you make changes to param names in any of +// the following objects. + const paramsByMethod = { access: ['path', 'mode'], appendFile: ['path', 'data', 'options'], diff --git a/packages/dd-trace/src/appsec/addresses.js b/packages/dd-trace/src/appsec/addresses.js index a492a5e454f..20290baf9c4 100644 --- a/packages/dd-trace/src/appsec/addresses.js +++ b/packages/dd-trace/src/appsec/addresses.js @@ -31,6 +31,7 @@ module.exports = { DB_STATEMENT: 'server.db.statement', DB_SYSTEM: 'server.db.system', + EXEC_COMMAND: 'server.sys.exec.cmd', SHELL_COMMAND: 'server.sys.shell.cmd', LOGIN_SUCCESS: 'server.business_logic.users.login.success', diff --git a/packages/dd-trace/src/appsec/rasp/command_injection.js b/packages/dd-trace/src/appsec/rasp/command_injection.js index 8d6d977aace..62546e2b6a6 100644 --- a/packages/dd-trace/src/appsec/rasp/command_injection.js +++ b/packages/dd-trace/src/appsec/rasp/command_injection.js @@ -25,19 +25,26 @@ function disable () { } function analyzeCommandInjection ({ file, fileArgs, shell, abortController }) { - if (!file || !shell) return + if (!file) return const store = storage.getStore() const req = store?.req if (!req) return - const commandParams = fileArgs ? [file, ...fileArgs] : file - - const persistent = { - [addresses.SHELL_COMMAND]: commandParams + const persistent = {} + const raspRule = { type: RULE_TYPES.COMMAND_INJECTION } + const params = fileArgs ? [file, ...fileArgs] : file + + if (shell) { + persistent[addresses.SHELL_COMMAND] = params + raspRule.variant = 'shell' + } else { + const commandParams = Array.isArray(params) ? params : [params] + persistent[addresses.EXEC_COMMAND] = commandParams + raspRule.variant = 'exec' } - const result = waf.run({ persistent }, req, RULE_TYPES.COMMAND_INJECTION) + const result = waf.run({ persistent }, req, raspRule) const res = store?.res handleResult(result, req, res, abortController, config) diff --git a/packages/dd-trace/src/appsec/rasp/lfi.js b/packages/dd-trace/src/appsec/rasp/lfi.js index 1190734064d..657369ad0fd 100644 --- a/packages/dd-trace/src/appsec/rasp/lfi.js +++ b/packages/dd-trace/src/appsec/rasp/lfi.js @@ -58,7 +58,9 @@ function analyzeLfi (ctx) { [FS_OPERATION_PATH]: path } - const result = waf.run({ persistent }, req, RULE_TYPES.LFI) + const raspRule = { type: RULE_TYPES.LFI } + + const result = waf.run({ persistent }, req, raspRule) handleResult(result, req, res, ctx.abortController, config) }) } diff --git a/packages/dd-trace/src/appsec/rasp/sql_injection.js b/packages/dd-trace/src/appsec/rasp/sql_injection.js index d4a165d8615..157723258f7 100644 --- a/packages/dd-trace/src/appsec/rasp/sql_injection.js +++ b/packages/dd-trace/src/appsec/rasp/sql_injection.js @@ -72,7 +72,9 @@ function analyzeSqlInjection (query, dbSystem, abortController) { [addresses.DB_SYSTEM]: dbSystem } - const result = waf.run({ persistent }, req, RULE_TYPES.SQL_INJECTION) + const raspRule = { type: RULE_TYPES.SQL_INJECTION } + + const result = waf.run({ persistent }, req, raspRule) handleResult(result, req, res, abortController, config) } diff --git a/packages/dd-trace/src/appsec/rasp/ssrf.js b/packages/dd-trace/src/appsec/rasp/ssrf.js index 38a3c150d74..7d429d74549 100644 --- a/packages/dd-trace/src/appsec/rasp/ssrf.js +++ b/packages/dd-trace/src/appsec/rasp/ssrf.js @@ -29,7 +29,9 @@ function analyzeSsrf (ctx) { [addresses.HTTP_OUTGOING_URL]: outgoingUrl } - const result = waf.run({ persistent }, req, RULE_TYPES.SSRF) + const raspRule = { type: RULE_TYPES.SSRF } + + const result = waf.run({ persistent }, req, raspRule) const res = store?.res handleResult(result, req, res, ctx.abortController, config) diff --git a/packages/dd-trace/src/appsec/remote_config/capabilities.js b/packages/dd-trace/src/appsec/remote_config/capabilities.js index 16034f5f9ee..5057d38de43 100644 --- a/packages/dd-trace/src/appsec/remote_config/capabilities.js +++ b/packages/dd-trace/src/appsec/remote_config/capabilities.js @@ -25,5 +25,6 @@ module.exports = { ASM_AUTO_USER_INSTRUM_MODE: 1n << 31n, ASM_ENDPOINT_FINGERPRINT: 1n << 32n, ASM_NETWORK_FINGERPRINT: 1n << 34n, - ASM_HEADER_FINGERPRINT: 1n << 35n + ASM_HEADER_FINGERPRINT: 1n << 35n, + ASM_RASP_CMDI: 1n << 37n } diff --git a/packages/dd-trace/src/appsec/remote_config/index.js b/packages/dd-trace/src/appsec/remote_config/index.js index 7884175abb0..6bebe40e142 100644 --- a/packages/dd-trace/src/appsec/remote_config/index.js +++ b/packages/dd-trace/src/appsec/remote_config/index.js @@ -101,6 +101,7 @@ function enableWafUpdate (appsecConfig) { rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_SSRF, true) rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_LFI, true) rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_SHI, true) + rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_CMDI, true) } // TODO: delete noop handlers and kPreUpdate and replace with batched handlers @@ -133,6 +134,7 @@ function disableWafUpdate () { rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_SSRF, false) rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_LFI, false) rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_SHI, false) + rc.updateCapabilities(RemoteConfigCapabilities.ASM_RASP_CMDI, false) rc.removeProductHandler('ASM_DATA') rc.removeProductHandler('ASM_DD') diff --git a/packages/dd-trace/src/appsec/reporter.js b/packages/dd-trace/src/appsec/reporter.js index 57519e5bc79..c2f9bac6cbc 100644 --- a/packages/dd-trace/src/appsec/reporter.js +++ b/packages/dd-trace/src/appsec/reporter.js @@ -101,7 +101,7 @@ function reportWafInit (wafVersion, rulesVersion, diagnosticsRules = {}) { incrementWafInitMetric(wafVersion, rulesVersion) } -function reportMetrics (metrics, raspRuleType) { +function reportMetrics (metrics, raspRule) { const store = storage.getStore() const rootSpan = store?.req && web.root(store.req) if (!rootSpan) return @@ -109,8 +109,8 @@ function reportMetrics (metrics, raspRuleType) { if (metrics.rulesVersion) { rootSpan.setTag('_dd.appsec.event_rules.version', metrics.rulesVersion) } - if (raspRuleType) { - updateRaspRequestsMetricTags(metrics, store.req, raspRuleType) + if (raspRule) { + updateRaspRequestsMetricTags(metrics, store.req, raspRule) } else { updateWafRequestsMetricTags(metrics, store.req) } diff --git a/packages/dd-trace/src/appsec/telemetry.js b/packages/dd-trace/src/appsec/telemetry.js index 8e9a2518f80..08f435b9c0e 100644 --- a/packages/dd-trace/src/appsec/telemetry.js +++ b/packages/dd-trace/src/appsec/telemetry.js @@ -79,7 +79,7 @@ function getOrCreateMetricTags (store, versionsTags) { return metricTags } -function updateRaspRequestsMetricTags (metrics, req, raspRuleType) { +function updateRaspRequestsMetricTags (metrics, req, raspRule) { if (!req) return const store = getStore(req) @@ -89,7 +89,12 @@ function updateRaspRequestsMetricTags (metrics, req, raspRuleType) { if (!enabled) return - const tags = { rule_type: raspRuleType, waf_version: metrics.wafVersion } + const tags = { rule_type: raspRule.type, waf_version: metrics.wafVersion } + + if (raspRule.variant) { + tags.rule_variant = raspRule.variant + } + appsecMetrics.count('rasp.rule.eval', tags).inc(1) if (metrics.wafTimeout) { diff --git a/packages/dd-trace/src/appsec/waf/index.js b/packages/dd-trace/src/appsec/waf/index.js index 3b2bc9e2a13..a14a5313a92 100644 --- a/packages/dd-trace/src/appsec/waf/index.js +++ b/packages/dd-trace/src/appsec/waf/index.js @@ -46,7 +46,7 @@ function update (newRules) { } } -function run (data, req, raspRuleType) { +function run (data, req, raspRule) { if (!req) { const store = storage.getStore() if (!store || !store.req) { @@ -59,7 +59,7 @@ function run (data, req, raspRuleType) { const wafContext = waf.wafManager.getWAFContext(req) - return wafContext.run(data, raspRuleType) + return wafContext.run(data, raspRule) } function disposeContext (req) { diff --git a/packages/dd-trace/src/appsec/waf/waf_context_wrapper.js b/packages/dd-trace/src/appsec/waf/waf_context_wrapper.js index 6a90b8f89bb..54dbd16e1be 100644 --- a/packages/dd-trace/src/appsec/waf/waf_context_wrapper.js +++ b/packages/dd-trace/src/appsec/waf/waf_context_wrapper.js @@ -21,7 +21,7 @@ class WAFContextWrapper { this.knownAddresses = knownAddresses } - run ({ persistent, ephemeral }, raspRuleType) { + run ({ persistent, ephemeral }, raspRule) { if (this.ddwafContext.disposed) { log.warn('[ASM] Calling run on a disposed context') return @@ -87,7 +87,7 @@ class WAFContextWrapper { blockTriggered, wafVersion: this.wafVersion, wafTimeout: result.timeout - }, raspRuleType) + }, raspRule) if (ruleTriggered) { Reporter.reportAttack(JSON.stringify(result.events)) diff --git a/packages/dd-trace/src/log/channels.js b/packages/dd-trace/src/log/channels.js index 545fef4195a..b3b10624705 100644 --- a/packages/dd-trace/src/log/channels.js +++ b/packages/dd-trace/src/log/channels.js @@ -3,7 +3,7 @@ const { channel } = require('dc-polyfill') const Level = { - trace: 20, + trace: 10, debug: 20, info: 30, warn: 40, @@ -12,6 +12,7 @@ const Level = { off: 100 } +const traceChannel = channel('datadog:log:trace') const debugChannel = channel('datadog:log:debug') const infoChannel = channel('datadog:log:info') const warnChannel = channel('datadog:log:warn') @@ -31,6 +32,9 @@ class LogChannel { } subscribe (logger) { + if (Level.trace >= this._level) { + traceChannel.subscribe(logger.trace) + } if (Level.debug >= this._level) { debugChannel.subscribe(logger.debug) } @@ -46,6 +50,9 @@ class LogChannel { } unsubscribe (logger) { + if (traceChannel.hasSubscribers) { + traceChannel.unsubscribe(logger.trace) + } if (debugChannel.hasSubscribers) { debugChannel.unsubscribe(logger.debug) } @@ -63,7 +70,7 @@ class LogChannel { module.exports = { LogChannel, - + traceChannel, debugChannel, infoChannel, warnChannel, diff --git a/packages/dd-trace/src/log/index.js b/packages/dd-trace/src/log/index.js index 3a5392340df..3fb9afff6fa 100644 --- a/packages/dd-trace/src/log/index.js +++ b/packages/dd-trace/src/log/index.js @@ -1,8 +1,9 @@ 'use strict' const coalesce = require('koalas') +const { inspect } = require('util') const { isTrue } = require('../util') -const { debugChannel, infoChannel, warnChannel, errorChannel } = require('./channels') +const { traceChannel, debugChannel, infoChannel, warnChannel, errorChannel } = require('./channels') const logWriter = require('./writer') const { Log } = require('./log') @@ -56,6 +57,25 @@ const log = { return this }, + trace (...args) { + if (traceChannel.hasSubscribers) { + const logRecord = {} + + Error.captureStackTrace(logRecord, this.trace) + + const fn = logRecord.stack.split('\n')[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)) + } + return this + }, + debug (...args) { if (debugChannel.hasSubscribers) { debugChannel.publish(Log.parse(...args)) diff --git a/packages/dd-trace/src/log/writer.js b/packages/dd-trace/src/log/writer.js index 4724253244b..322c703b2b3 100644 --- a/packages/dd-trace/src/log/writer.js +++ b/packages/dd-trace/src/log/writer.js @@ -23,7 +23,7 @@ function withNoop (fn) { } function unsubscribeAll () { - logChannel.unsubscribe({ debug: onDebug, info: onInfo, warn: onWarn, error: onError }) + logChannel.unsubscribe({ trace: onTrace, debug: onDebug, info: onInfo, warn: onWarn, error: onError }) } function toggleSubscription (enable, level) { @@ -31,7 +31,7 @@ function toggleSubscription (enable, level) { if (enable) { logChannel = new LogChannel(level) - logChannel.subscribe({ debug: onDebug, info: onInfo, warn: onWarn, error: onError }) + logChannel.subscribe({ trace: onTrace, debug: onDebug, info: onInfo, warn: onWarn, error: onError }) } } @@ -88,6 +88,14 @@ function onDebug (log) { if (cause) withNoop(() => logger.debug(cause)) } +function onTrace (log) { + const { formatted, cause } = getErrorLog(log) + // Using logger.debug() because not all loggers have trace level, + // and console.trace() has a completely different meaning. + if (formatted) withNoop(() => logger.debug(formatted)) + if (cause) withNoop(() => logger.debug(cause)) +} + function error (...args) { onError(Log.parse(...args)) } @@ -110,4 +118,8 @@ function debug (...args) { onDebug(Log.parse(...args)) } -module.exports = { use, toggle, reset, error, warn, info, debug } +function trace (...args) { + onTrace(Log.parse(...args)) +} + +module.exports = { use, toggle, reset, error, warn, info, debug, trace } diff --git a/packages/dd-trace/src/opentracing/span.js b/packages/dd-trace/src/opentracing/span.js index 00fd51da027..23f885bbabd 100644 --- a/packages/dd-trace/src/opentracing/span.js +++ b/packages/dd-trace/src/opentracing/span.js @@ -107,7 +107,7 @@ class DatadogSpan { toString () { const spanContext = this.context() - const resourceName = spanContext._tags['resource.name'] + const resourceName = spanContext._tags['resource.name'] || '' const resource = resourceName.length > 100 ? `${resourceName.substring(0, 97)}...` : resourceName diff --git a/packages/dd-trace/src/priority_sampler.js b/packages/dd-trace/src/priority_sampler.js index f9968a41194..3a89f71f664 100644 --- a/packages/dd-trace/src/priority_sampler.js +++ b/packages/dd-trace/src/priority_sampler.js @@ -1,5 +1,6 @@ 'use strict' +const log = require('./log') const RateLimiter = require('./rate_limiter') const Sampler = require('./sampler') const { setSamplingRules } = require('./startup-log') @@ -44,16 +45,19 @@ class PrioritySampler { this.update({}) } - configure (env, { sampleRate, provenance = undefined, rateLimit = 100, rules = [] } = {}) { + configure (env, opts = {}) { + const { sampleRate, provenance = undefined, rateLimit = 100, rules = [] } = opts this._env = env this._rules = this._normalizeRules(rules, sampleRate, rateLimit, provenance) this._limiter = new RateLimiter(rateLimit) + log.trace(env, opts) setSamplingRules(this._rules) } isSampled (span) { const priority = this._getPriorityFromAuto(span) + log.trace(span) return priority === USER_KEEP || priority === AUTO_KEEP } @@ -67,6 +71,8 @@ class PrioritySampler { if (context._sampling.priority !== undefined) return if (!root) return // noop span + log.trace(span, auto) + const tag = this._getPriorityFromTags(context._tags, context) if (this.validate(tag)) { @@ -94,6 +100,8 @@ class PrioritySampler { samplers[DEFAULT_KEY] = samplers[DEFAULT_KEY] || defaultSampler this._samplers = samplers + + log.trace(rates) } validate (samplingPriority) { @@ -117,6 +125,8 @@ class PrioritySampler { context._sampling.mechanism = mechanism const root = context._trace.started[0] + + log.trace(span, samplingPriority, mechanism) this._addDecisionMaker(root) } diff --git a/packages/dd-trace/src/profiling/profilers/event_plugins/event.js b/packages/dd-trace/src/profiling/profilers/event_plugins/event.js index 48e430ba607..eace600a9aa 100644 --- a/packages/dd-trace/src/profiling/profilers/event_plugins/event.js +++ b/packages/dd-trace/src/profiling/profilers/event_plugins/event.js @@ -32,11 +32,11 @@ class EventPlugin extends TracingPlugin { if (!store) return const { startEvent, startTime, error } = store - if (error) { - return // don't emit perf events for failed operations + if (error || this.ignoreEvent(startEvent)) { + return // don't emit perf events for failed operations or ignored events } - const duration = performance.now() - startTime + const duration = performance.now() - startTime const event = { entryType: this.entryType, startTime, @@ -53,6 +53,10 @@ class EventPlugin extends TracingPlugin { this.eventHandler(this.extendEvent(event, startEvent)) } + + ignoreEvent () { + return false + } } module.exports = EventPlugin diff --git a/packages/dd-trace/src/profiling/profilers/event_plugins/fs.js b/packages/dd-trace/src/profiling/profilers/event_plugins/fs.js new file mode 100644 index 00000000000..34eb7b52353 --- /dev/null +++ b/packages/dd-trace/src/profiling/profilers/event_plugins/fs.js @@ -0,0 +1,49 @@ +const EventPlugin = require('./event') + +// Values taken from parameter names in datadog-instrumentations/src/fs.js. +// Known param names that are disallowed because they can be strings and have arbitrary sizes: +// 'data' +// Known param names that are disallowed because they are never a string or number: +// 'buffer', 'buffers', 'listener' +const allowedParams = new Set([ + 'atime', 'dest', + 'existingPath', 'fd', 'file', + 'flag', 'gid', 'len', + 'length', 'mode', 'mtime', + 'newPath', 'offset', 'oldPath', + 'operation', 'options', 'path', + 'position', 'prefix', 'src', + 'target', 'type', 'uid' +]) + +class FilesystemPlugin extends EventPlugin { + static get id () { + return 'fs' + } + + static get operation () { + return 'operation' + } + + static get entryType () { + return 'fs' + } + + ignoreEvent (event) { + // Don't care about sync events, they show up in the event loop samples anyway + return event.operation?.endsWith('Sync') + } + + extendEvent (event, detail) { + const d = { ...detail } + Object.entries(d).forEach(([k, v]) => { + if (!(allowedParams.has(k) && (typeof v === 'string' || typeof v === 'number'))) { + delete d[k] + } + }) + event.detail = d + + return event + } +} +module.exports = FilesystemPlugin diff --git a/packages/dd-trace/src/profiling/profilers/events.js b/packages/dd-trace/src/profiling/profilers/events.js index 2200eaadd2e..8ff1748ceda 100644 --- a/packages/dd-trace/src/profiling/profilers/events.js +++ b/packages/dd-trace/src/profiling/profilers/events.js @@ -133,11 +133,32 @@ class NetDecorator { } } +class FilesystemDecorator { + constructor (stringTable) { + this.stringTable = stringTable + } + + decorateSample (sampleInput, item) { + const labels = sampleInput.label + const stringTable = this.stringTable + Object.entries(item.detail).forEach(([k, v]) => { + switch (typeof v) { + case 'string': + labels.push(labelFromStrStr(stringTable, k, v)) + break + case 'number': + labels.push(new Label({ key: stringTable.dedup(k), num: v })) + } + }) + } +} + // Keys correspond to PerformanceEntry.entryType, values are constructor // functions for type-specific decorators. const decoratorTypes = { - gc: GCDecorator, + fs: FilesystemDecorator, dns: DNSDecorator, + gc: GCDecorator, net: NetDecorator } @@ -255,7 +276,7 @@ class NodeApiEventSource { class DatadogInstrumentationEventSource { constructor (eventHandler, eventFilter) { - this.plugins = ['dns_lookup', 'dns_lookupservice', 'dns_resolve', 'dns_reverse', 'net'].map(m => { + this.plugins = ['dns_lookup', 'dns_lookupservice', 'dns_resolve', 'dns_reverse', 'fs', 'net'].map(m => { const Plugin = require(`./event_plugins/${m}`) return new Plugin(eventHandler, eventFilter) }) diff --git a/packages/dd-trace/test/appsec/rasp/command_injection.express.plugin.spec.js b/packages/dd-trace/test/appsec/rasp/command_injection.express.plugin.spec.js index 3943bd0c3c3..d7609367ab9 100644 --- a/packages/dd-trace/test/appsec/rasp/command_injection.express.plugin.spec.js +++ b/packages/dd-trace/test/appsec/rasp/command_injection.express.plugin.spec.js @@ -5,42 +5,25 @@ const appsec = require('../../../src/appsec') const Config = require('../../../src/config') const path = require('path') const Axios = require('axios') -const { getWebSpan, checkRaspExecutedAndHasThreat, checkRaspExecutedAndNotThreat } = require('./utils') +const { checkRaspExecutedAndHasThreat, checkRaspExecutedAndNotThreat } = require('./utils') const { assert } = require('chai') describe('RASP - command_injection', () => { withVersions('express', 'express', expressVersion => { let app, server, axios + function testShellBlockingAndSafeRequests () { + it('should block the threat', async () => { + try { + await axios.get('/?dir=$(cat /etc/passwd 1>%262 ; echo .)') + } catch (e) { + if (!e.response) { + throw e + } - async function testBlockingRequest () { - try { - await axios.get('/?dir=$(cat /etc/passwd 1>%262 ; echo .)') - } catch (e) { - if (!e.response) { - throw e - } - - return checkRaspExecutedAndHasThreat(agent, 'rasp-command_injection-rule-id-3') - } - - assert.fail('Request should be blocked') - } - - function checkRaspNotExecutedAndNotThreat (agent, checkRuleEval = true) { - return agent.use((traces) => { - const span = getWebSpan(traces) - - assert.notProperty(span.meta, '_dd.appsec.json') - assert.notProperty(span.meta_struct || {}, '_dd.stack') - if (checkRuleEval) { - assert.notProperty(span.metrics, '_dd.appsec.rasp.rule.eval') + return checkRaspExecutedAndHasThreat(agent, 'rasp-command_injection-rule-id-3') } - }) - } - function testBlockingAndSafeRequests () { - it('should block the threat', async () => { - await testBlockingRequest() + assert.fail('Request should be blocked') }) it('should not block safe request', async () => { @@ -50,17 +33,25 @@ describe('RASP - command_injection', () => { }) } - function testSafeInNonShell () { - it('should not block the threat', async () => { - await axios.get('/?dir=$(cat /etc/passwd 1>%262 ; echo .)') + function testNonShellBlockingAndSafeRequests () { + it('should block the threat', async () => { + try { + await axios.get('/?command=/usr/bin/reboot') + } catch (e) { + if (!e.response) { + throw e + } - return checkRaspNotExecutedAndNotThreat(agent) + return checkRaspExecutedAndHasThreat(agent, 'rasp-command_injection-rule-id-4') + } + + assert.fail('Request should be blocked') }) it('should not block safe request', async () => { - await axios.get('/?dir=.') + await axios.get('/?command=.') - return checkRaspNotExecutedAndNotThreat(agent) + return checkRaspExecutedAndNotThreat(agent) }) } @@ -116,7 +107,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('with promise', () => { @@ -137,7 +128,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('with event emitter', () => { @@ -158,7 +149,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('execSync', () => { @@ -178,7 +169,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) }) @@ -199,7 +190,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('with promise', () => { @@ -220,7 +211,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('with event emitter', () => { @@ -241,7 +232,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('execFileSync', () => { @@ -261,7 +252,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) }) @@ -271,7 +262,7 @@ describe('RASP - command_injection', () => { app = (req, res) => { const childProcess = require('child_process') - childProcess.execFile('ls', [req.query.dir], function (e) { + childProcess.execFile(req.query.command, function (e) { if (e?.name === 'DatadogRaspAbortError') { res.writeHead(500) } @@ -281,7 +272,7 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) describe('with promise', () => { @@ -291,7 +282,7 @@ describe('RASP - command_injection', () => { const execFile = util.promisify(require('child_process').execFile) try { - await execFile('ls', [req.query.dir]) + await execFile([req.query.command]) } catch (e) { if (e.name === 'DatadogRaspAbortError') { res.writeHead(500) @@ -302,15 +293,14 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) describe('with event emitter', () => { beforeEach(() => { app = (req, res) => { const childProcess = require('child_process') - - const child = childProcess.execFile('ls', [req.query.dir]) + const child = childProcess.execFile(req.query.command) child.on('error', (e) => { if (e.name === 'DatadogRaspAbortError') { res.writeHead(500) @@ -323,7 +313,7 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) describe('execFileSync', () => { @@ -332,7 +322,7 @@ describe('RASP - command_injection', () => { const childProcess = require('child_process') try { - childProcess.execFileSync('ls', [req.query.dir]) + childProcess.execFileSync([req.query.command]) } catch (e) { if (e.name === 'DatadogRaspAbortError') { res.writeHead(500) @@ -343,7 +333,7 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) }) }) @@ -368,7 +358,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) describe('spawnSync', () => { @@ -385,7 +375,7 @@ describe('RASP - command_injection', () => { } }) - testBlockingAndSafeRequests() + testShellBlockingAndSafeRequests() }) }) @@ -395,7 +385,7 @@ describe('RASP - command_injection', () => { app = (req, res) => { const childProcess = require('child_process') - const child = childProcess.spawn('ls', [req.query.dir]) + const child = childProcess.spawn(req.query.command) child.on('error', (e) => { if (e.name === 'DatadogRaspAbortError') { res.writeHead(500) @@ -408,7 +398,7 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) describe('spawnSync', () => { @@ -416,7 +406,7 @@ describe('RASP - command_injection', () => { app = (req, res) => { const childProcess = require('child_process') - const child = childProcess.spawnSync('ls', [req.query.dir]) + const child = childProcess.spawnSync(req.query.command) if (child.error?.name === 'DatadogRaspAbortError') { res.writeHead(500) } @@ -425,7 +415,7 @@ describe('RASP - command_injection', () => { } }) - testSafeInNonShell() + testNonShellBlockingAndSafeRequests() }) }) }) diff --git a/packages/dd-trace/test/appsec/rasp/command_injection.integration.spec.js b/packages/dd-trace/test/appsec/rasp/command_injection.integration.spec.js index 4ebb8c4910a..d6fe4015202 100644 --- a/packages/dd-trace/test/appsec/rasp/command_injection.integration.spec.js +++ b/packages/dd-trace/test/appsec/rasp/command_injection.integration.spec.js @@ -42,6 +42,7 @@ describe('RASP - command_injection - integration', () => { APP_PORT: appPort, DD_APPSEC_ENABLED: 'true', DD_APPSEC_RASP_ENABLED: 'true', + DD_TELEMETRY_HEARTBEAT_INTERVAL: 1, DD_APPSEC_RULES: path.join(cwd, 'resources', 'rasp_rules.json') } }) @@ -52,7 +53,7 @@ describe('RASP - command_injection - integration', () => { await agent.stop() }) - async function testRequestBlocked (url) { + async function testRequestBlocked (url, ruleId = 3, variant = 'shell') { try { await axios.get(url) } catch (e) { @@ -61,28 +62,72 @@ describe('RASP - command_injection - integration', () => { } assert.strictEqual(e.response.status, 403) - return await agent.assertMessageReceived(({ headers, payload }) => { + + let appsecTelemetryReceived = false + + const checkMessages = await agent.assertMessageReceived(({ headers, payload }) => { assert.property(payload[0][0].meta, '_dd.appsec.json') - assert.include(payload[0][0].meta['_dd.appsec.json'], '"rasp-command_injection-rule-id-3"') + assert.include(payload[0][0].meta['_dd.appsec.json'], `"rasp-command_injection-rule-id-${ruleId}"`) }) + + const checkTelemetry = await agent.assertTelemetryReceived(({ headers, payload }) => { + const namespace = payload.payload.namespace + + // Only check telemetry received in appsec namespace and ignore others + if (namespace === 'appsec') { + appsecTelemetryReceived = true + const series = payload.payload.series + const evalSerie = series.find(s => s.metric === 'rasp.rule.eval') + const matchSerie = series.find(s => s.metric === 'rasp.rule.match') + + assert.exists(evalSerie, 'eval serie should exist') + assert.include(evalSerie.tags, 'rule_type:command_injection') + assert.include(evalSerie.tags, `rule_variant:${variant}`) + assert.strictEqual(evalSerie.type, 'count') + + assert.exists(matchSerie, 'match serie should exist') + assert.include(matchSerie.tags, 'rule_type:command_injection') + assert.include(matchSerie.tags, `rule_variant:${variant}`) + assert.strictEqual(matchSerie.type, 'count') + } + }, 30_000, 'generate-metrics', 2) + + const checks = await Promise.all([checkMessages, checkTelemetry]) + assert.equal(appsecTelemetryReceived, true) + + return checks } throw new Error('Request should be blocked') } - it('should block using execFileSync and exception handled by express', async () => { - await testRequestBlocked('/shi/execFileSync?dir=$(cat /etc/passwd 1>%262 ; echo .)') - }) + describe('with shell', () => { + it('should block using execFileSync and exception handled by express', async () => { + await testRequestBlocked('/shi/execFileSync?dir=$(cat /etc/passwd 1>%262 ; echo .)') + }) - it('should block using execFileSync and unhandled exception', async () => { - await testRequestBlocked('/shi/execFileSync/out-of-express-scope?dir=$(cat /etc/passwd 1>%262 ; echo .)') - }) + it('should block using execFileSync and unhandled exception', async () => { + await testRequestBlocked('/shi/execFileSync/out-of-express-scope?dir=$(cat /etc/passwd 1>%262 ; echo .)') + }) + + it('should block using execSync and exception handled by express', async () => { + await testRequestBlocked('/shi/execSync?dir=$(cat /etc/passwd 1>%262 ; echo .)') + }) - it('should block using execSync and exception handled by express', async () => { - await testRequestBlocked('/shi/execSync?dir=$(cat /etc/passwd 1>%262 ; echo .)') + it('should block using execSync and unhandled exception', async () => { + await testRequestBlocked('/shi/execSync/out-of-express-scope?dir=$(cat /etc/passwd 1>%262 ; echo .)') + }) }) - it('should block using execSync and unhandled exception', async () => { - await testRequestBlocked('/shi/execSync/out-of-express-scope?dir=$(cat /etc/passwd 1>%262 ; echo .)') + describe('without shell', () => { + it('should block using execFileSync and exception handled by express', async () => { + await testRequestBlocked('/cmdi/execFileSync?command=cat /etc/passwd 1>&2 ; echo .', 4, 'exec') + }) + + it('should block using execFileSync and unhandled exception', async () => { + await testRequestBlocked( + '/cmdi/execFileSync/out-of-express-scope?command=cat /etc/passwd 1>&2 ; echo .', 4, 'exec' + ) + }) }) }) diff --git a/packages/dd-trace/test/appsec/rasp/command_injection.spec.js b/packages/dd-trace/test/appsec/rasp/command_injection.spec.js index 785b155a113..bf920940c7a 100644 --- a/packages/dd-trace/test/appsec/rasp/command_injection.spec.js +++ b/packages/dd-trace/test/appsec/rasp/command_injection.spec.js @@ -49,49 +49,6 @@ describe('RASP - command_injection.js', () => { }) describe('analyzeCommandInjection', () => { - it('should analyze command_injection without arguments', () => { - const ctx = { - file: 'cmd', - shell: true - } - const req = {} - datadogCore.storage.getStore.returns({ req }) - - start.publish(ctx) - - const persistent = { [addresses.SHELL_COMMAND]: 'cmd' } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'command_injection') - }) - - it('should analyze command_injection with arguments', () => { - const ctx = { - file: 'cmd', - fileArgs: ['arg0', 'arg1'], - shell: true - } - const req = {} - datadogCore.storage.getStore.returns({ req }) - - start.publish(ctx) - - const persistent = { [addresses.SHELL_COMMAND]: ['cmd', 'arg0', 'arg1'] } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'command_injection') - }) - - it('should not analyze command_injection when it is not shell', () => { - const ctx = { - file: 'cmd', - fileArgs: ['arg0', 'arg1'], - shell: false - } - const req = {} - datadogCore.storage.getStore.returns({ req }) - - start.publish(ctx) - - sinon.assert.notCalled(waf.run) - }) - it('should not analyze command_injection if rasp is disabled', () => { commandInjection.disable() const ctx = { @@ -139,18 +96,102 @@ describe('RASP - command_injection.js', () => { sinon.assert.notCalled(waf.run) }) - it('should call handleResult', () => { - const abortController = { abort: 'abort' } - const ctx = { file: 'cmd', abortController, shell: true } - const wafResult = { waf: 'waf' } - const req = { req: 'req' } - const res = { res: 'res' } - waf.run.returns(wafResult) - datadogCore.storage.getStore.returns({ req, res }) - - start.publish(ctx) + describe('command_injection with shell', () => { + it('should analyze command_injection without arguments', () => { + const ctx = { + file: 'cmd', + shell: true + } + const req = {} + datadogCore.storage.getStore.returns({ req }) + + start.publish(ctx) + + const persistent = { [addresses.SHELL_COMMAND]: 'cmd' } + sinon.assert.calledOnceWithExactly( + waf.run, { persistent }, req, { type: 'command_injection', variant: 'shell' } + ) + }) + + it('should analyze command_injection with arguments', () => { + const ctx = { + file: 'cmd', + fileArgs: ['arg0', 'arg1'], + shell: true + } + const req = {} + datadogCore.storage.getStore.returns({ req }) + + start.publish(ctx) + + const persistent = { [addresses.SHELL_COMMAND]: ['cmd', 'arg0', 'arg1'] } + sinon.assert.calledOnceWithExactly( + waf.run, { persistent }, req, { type: 'command_injection', variant: 'shell' } + ) + }) + + it('should call handleResult', () => { + const abortController = { abort: 'abort' } + const ctx = { file: 'cmd', abortController, shell: true } + const wafResult = { waf: 'waf' } + const req = { req: 'req' } + const res = { res: 'res' } + waf.run.returns(wafResult) + datadogCore.storage.getStore.returns({ req, res }) + + start.publish(ctx) + + sinon.assert.calledOnceWithExactly(utils.handleResult, wafResult, req, res, abortController, config) + }) + }) - sinon.assert.calledOnceWithExactly(utils.handleResult, wafResult, req, res, abortController, config) + describe('command_injection without shell', () => { + it('should analyze command injection without arguments', () => { + const ctx = { + file: 'ls', + shell: false + } + const req = {} + datadogCore.storage.getStore.returns({ req }) + + start.publish(ctx) + + const persistent = { [addresses.EXEC_COMMAND]: ['ls'] } + sinon.assert.calledOnceWithExactly( + waf.run, { persistent }, req, { type: 'command_injection', variant: 'exec' } + ) + }) + + it('should analyze command injection with arguments', () => { + const ctx = { + file: 'ls', + fileArgs: ['-la', '/tmp'], + shell: false + } + const req = {} + datadogCore.storage.getStore.returns({ req }) + + start.publish(ctx) + + const persistent = { [addresses.EXEC_COMMAND]: ['ls', '-la', '/tmp'] } + sinon.assert.calledOnceWithExactly( + waf.run, { persistent }, req, { type: 'command_injection', variant: 'exec' } + ) + }) + + it('should call handleResult', () => { + const abortController = { abort: 'abort' } + const ctx = { file: 'cmd', abortController, shell: false } + const wafResult = { waf: 'waf' } + const req = { req: 'req' } + const res = { res: 'res' } + waf.run.returns(wafResult) + datadogCore.storage.getStore.returns({ req, res }) + + start.publish(ctx) + + sinon.assert.calledOnceWithExactly(utils.handleResult, wafResult, req, res, abortController, config) + }) }) }) }) diff --git a/packages/dd-trace/test/appsec/rasp/lfi.spec.js b/packages/dd-trace/test/appsec/rasp/lfi.spec.js index 405311ae0d3..0a1328e2c52 100644 --- a/packages/dd-trace/test/appsec/rasp/lfi.spec.js +++ b/packages/dd-trace/test/appsec/rasp/lfi.spec.js @@ -111,7 +111,7 @@ describe('RASP - lfi.js', () => { fsOperationStart.publish(ctx) const persistent = { [FS_OPERATION_PATH]: path } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'lfi') + sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, { type: 'lfi' }) }) it('should NOT analyze lfi for child fs operations', () => { diff --git a/packages/dd-trace/test/appsec/rasp/resources/rasp_rules.json b/packages/dd-trace/test/appsec/rasp/resources/rasp_rules.json index daca47d8d20..c0396bd9871 100644 --- a/packages/dd-trace/test/appsec/rasp/resources/rasp_rules.json +++ b/packages/dd-trace/test/appsec/rasp/resources/rasp_rules.json @@ -110,7 +110,7 @@ }, { "id": "rasp-command_injection-rule-id-3", - "name": "Command injection exploit", + "name": "Shell command injection exploit", "tags": { "type": "command_injection", "category": "vulnerability_trigger", @@ -156,6 +156,55 @@ "block", "stack_trace" ] + }, + { + "id": "rasp-command_injection-rule-id-4", + "name": "OS command injection exploit", + "tags": { + "type": "command_injection", + "category": "vulnerability_trigger", + "cwe": "77", + "capec": "1000/152/248/88", + "confidence": "0", + "module": "rasp" + }, + "conditions": [ + { + "parameters": { + "resource": [ + { + "address": "server.sys.exec.cmd" + } + ], + "params": [ + { + "address": "server.request.query" + }, + { + "address": "server.request.body" + }, + { + "address": "server.request.path_params" + }, + { + "address": "grpc.server.request.message" + }, + { + "address": "graphql.server.all_resolvers" + }, + { + "address": "graphql.server.resolver" + } + ] + }, + "operator": "cmdi_detector" + } + ], + "transformers": [], + "on_match": [ + "block", + "stack_trace" + ] } ] } diff --git a/packages/dd-trace/test/appsec/rasp/resources/shi-app/index.js b/packages/dd-trace/test/appsec/rasp/resources/shi-app/index.js index a6714bd2148..133c57dfb2b 100644 --- a/packages/dd-trace/test/appsec/rasp/resources/shi-app/index.js +++ b/packages/dd-trace/test/appsec/rasp/resources/shi-app/index.js @@ -39,6 +39,20 @@ app.get('/shi/execSync/out-of-express-scope', async (req, res) => { }) }) +app.get('/cmdi/execFileSync', async (req, res) => { + childProcess.execFileSync('sh', ['-c', req.query.command]) + + res.end('OK') +}) + +app.get('/cmdi/execFileSync/out-of-express-scope', async (req, res) => { + process.nextTick(() => { + childProcess.execFileSync('sh', ['-c', req.query.command]) + + res.end('OK') + }) +}) + app.listen(port, () => { process.send({ port }) }) diff --git a/packages/dd-trace/test/appsec/rasp/sql_injection.pg.plugin.spec.js b/packages/dd-trace/test/appsec/rasp/sql_injection.pg.plugin.spec.js index 8f05158c22d..2d4dd779c17 100644 --- a/packages/dd-trace/test/appsec/rasp/sql_injection.pg.plugin.spec.js +++ b/packages/dd-trace/test/appsec/rasp/sql_injection.pg.plugin.spec.js @@ -219,7 +219,7 @@ describe('RASP - sql_injection', () => { await axios.get('/') - assert.equal(run.args.filter(arg => arg[1] === 'sql_injection').length, 1) + assert.equal(run.args.filter(arg => arg[1]?.type === 'sql_injection').length, 1) }) it('should call to waf twice for sql injection with two different queries in pg Pool', async () => { @@ -232,7 +232,7 @@ describe('RASP - sql_injection', () => { await axios.get('/') - assert.equal(run.args.filter(arg => arg[1] === 'sql_injection').length, 2) + assert.equal(run.args.filter(arg => arg[1]?.type === 'sql_injection').length, 2) }) it('should call to waf twice for sql injection and same query when input address is updated', async () => { @@ -254,7 +254,7 @@ describe('RASP - sql_injection', () => { await axios.get('/') - assert.equal(run.args.filter(arg => arg[1] === 'sql_injection').length, 2) + assert.equal(run.args.filter(arg => arg[1]?.type === 'sql_injection').length, 2) }) it('should call to waf once for sql injection and same query when input address is updated', async () => { @@ -276,7 +276,7 @@ describe('RASP - sql_injection', () => { await axios.get('/') - assert.equal(run.args.filter(arg => arg[1] === 'sql_injection').length, 1) + assert.equal(run.args.filter(arg => arg[1]?.type === 'sql_injection').length, 1) }) }) }) diff --git a/packages/dd-trace/test/appsec/rasp/sql_injection.spec.js b/packages/dd-trace/test/appsec/rasp/sql_injection.spec.js index d713521e986..fe7c9af082d 100644 --- a/packages/dd-trace/test/appsec/rasp/sql_injection.spec.js +++ b/packages/dd-trace/test/appsec/rasp/sql_injection.spec.js @@ -57,7 +57,7 @@ describe('RASP - sql_injection', () => { [addresses.DB_STATEMENT]: 'SELECT 1', [addresses.DB_SYSTEM]: 'postgresql' } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'sql_injection') + sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, { type: 'sql_injection' }) }) it('should not analyze sql injection if rasp is disabled', () => { @@ -128,7 +128,7 @@ describe('RASP - sql_injection', () => { [addresses.DB_STATEMENT]: 'SELECT 1', [addresses.DB_SYSTEM]: 'mysql' } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'sql_injection') + sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, { type: 'sql_injection' }) }) it('should not analyze sql injection if rasp is disabled', () => { diff --git a/packages/dd-trace/test/appsec/rasp/ssrf.spec.js b/packages/dd-trace/test/appsec/rasp/ssrf.spec.js index c40867ea254..98d5c8a0104 100644 --- a/packages/dd-trace/test/appsec/rasp/ssrf.spec.js +++ b/packages/dd-trace/test/appsec/rasp/ssrf.spec.js @@ -54,7 +54,7 @@ describe('RASP - ssrf.js', () => { httpClientRequestStart.publish(ctx) const persistent = { [addresses.HTTP_OUTGOING_URL]: 'http://example.com' } - sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, 'ssrf') + sinon.assert.calledOnceWithExactly(waf.run, { persistent }, req, { type: 'ssrf' }) }) it('should not analyze ssrf if rasp is disabled', () => { diff --git a/packages/dd-trace/test/appsec/remote_config/index.spec.js b/packages/dd-trace/test/appsec/remote_config/index.spec.js index f3cc6a32dac..4d296d100d1 100644 --- a/packages/dd-trace/test/appsec/remote_config/index.spec.js +++ b/packages/dd-trace/test/appsec/remote_config/index.spec.js @@ -244,6 +244,8 @@ describe('Remote Config index', () => { .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_LFI, true) expect(rc.updateCapabilities) .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_SHI, true) + expect(rc.updateCapabilities) + .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_CMDI, true) expect(rc.setProductHandler).to.have.been.calledWith('ASM_DATA') expect(rc.setProductHandler).to.have.been.calledWith('ASM_DD') @@ -288,6 +290,8 @@ describe('Remote Config index', () => { .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_LFI, true) expect(rc.updateCapabilities) .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_SHI, true) + expect(rc.updateCapabilities) + .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_CMDI, true) expect(rc.setProductHandler).to.have.been.calledWith('ASM_DATA') expect(rc.setProductHandler).to.have.been.calledWith('ASM_DD') @@ -334,6 +338,8 @@ describe('Remote Config index', () => { .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_LFI, true) expect(rc.updateCapabilities) .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_SHI, true) + expect(rc.updateCapabilities) + .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_CMDI, true) }) it('should not activate rasp capabilities if rasp is disabled', () => { @@ -375,6 +381,8 @@ describe('Remote Config index', () => { .to.not.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_LFI) expect(rc.updateCapabilities) .to.not.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_SHI) + expect(rc.updateCapabilities) + .to.not.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_CMDI) }) }) @@ -416,6 +424,8 @@ describe('Remote Config index', () => { .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_LFI, false) expect(rc.updateCapabilities) .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_SHI, false) + expect(rc.updateCapabilities) + .to.have.been.calledWithExactly(RemoteConfigCapabilities.ASM_RASP_CMDI, false) expect(rc.removeProductHandler).to.have.been.calledWith('ASM_DATA') expect(rc.removeProductHandler).to.have.been.calledWith('ASM_DD') diff --git a/packages/dd-trace/test/appsec/reporter.spec.js b/packages/dd-trace/test/appsec/reporter.spec.js index cd7cc9a1581..a38092e728d 100644 --- a/packages/dd-trace/test/appsec/reporter.spec.js +++ b/packages/dd-trace/test/appsec/reporter.spec.js @@ -192,13 +192,15 @@ describe('reporter', () => { expect(telemetry.updateRaspRequestsMetricTags).to.not.have.been.called }) - it('should call updateRaspRequestsMetricTags when ruleType if provided', () => { + it('should call updateRaspRequestsMetricTags when raspRule is provided', () => { const metrics = { rulesVersion: '1.2.3' } const store = storage.getStore() - Reporter.reportMetrics(metrics, 'rule_type') + const raspRule = { type: 'rule_type', variant: 'rule_variant' } - expect(telemetry.updateRaspRequestsMetricTags).to.have.been.calledOnceWithExactly(metrics, store.req, 'rule_type') + Reporter.reportMetrics(metrics, raspRule) + + expect(telemetry.updateRaspRequestsMetricTags).to.have.been.calledOnceWithExactly(metrics, store.req, raspRule) expect(telemetry.updateWafRequestsMetricTags).to.not.have.been.called }) }) diff --git a/packages/dd-trace/test/log.spec.js b/packages/dd-trace/test/log.spec.js index a035c864f71..16682f97db8 100644 --- a/packages/dd-trace/test/log.spec.js +++ b/packages/dd-trace/test/log.spec.js @@ -139,6 +139,27 @@ describe('log', () => { }) }) + describe('trace', () => { + it('should not log to console by default', () => { + log.trace('trace') + + expect(console.debug).to.not.have.been.called + }) + + it('should log to console after setting log level to trace', function foo () { + log.toggle(true, 'trace') + log.trace('argument', { hello: 'world' }, { + toString: () => 'string' + }, { foo: 'bar' }) + + expect(console.debug).to.have.been.calledOnce + expect(console.debug.firstCall.args[0]).to.match( + /^Trace: Test.foo\('argument', { hello: 'world' }, string, { foo: 'bar' }\)/ + ) + expect(console.debug.firstCall.args[0].split('\n').length).to.be.gte(3) + }) + }) + describe('error', () => { it('should log to console by default', () => { log.error(error)