From 3f0e5bbf106122a9172c00078f6e49dba6da64a6 Mon Sep 17 00:00:00 2001 From: Bryan English Date: Wed, 26 Jun 2024 10:22:48 -0400 Subject: [PATCH] Add runtime guardrail for SSI (#4319) * Add guardrails for SSI * PR feedback * test on a swath of versions, in CI only --- .github/workflows/project.yml | 14 + init.js | 41 ++- initialize.mjs | 13 +- integration-tests/helpers.js | 181 ++++++++++++- integration-tests/init.spec.js | 240 +++++++++++------- integration-tests/package-guardrails.spec.js | 95 +++++++ integration-tests/package-guardrails/index.js | 8 + integration-tests/telemetry-forwarder.sh | 7 + .../src/helpers/register.js | 31 ++- .../dd-trace/src/telemetry/init-telemetry.js | 75 ++++++ 10 files changed, 606 insertions(+), 99 deletions(-) create mode 100644 integration-tests/package-guardrails.spec.js create mode 100644 integration-tests/package-guardrails/index.js create mode 100755 integration-tests/telemetry-forwarder.sh create mode 100644 packages/dd-trace/src/telemetry/init-telemetry.js diff --git a/.github/workflows/project.yml b/.github/workflows/project.yml index 258d827bdf2..a74051512ba 100644 --- a/.github/workflows/project.yml +++ b/.github/workflows/project.yml @@ -30,6 +30,20 @@ jobs: - run: sudo sysctl -w kernel.core_pattern='|/bin/false' - run: yarn test:integration + # We'll run these separately for earlier (i.e. unsupported) versions + integration-guardrails: + strategy: + matrix: + version: [12, 14, 16] + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v4 + - uses: actions/setup-node@v3 + with: + node-version: ${{ matrix.version }} + - run: yarn install --ignore-engines + - run: node node_modules/.bin/mocha --colors --timeout 30000 -r packages/dd-trace/test/setup/core.js integration-tests/init.spec.js + integration-ci: strategy: matrix: diff --git a/init.js b/init.js index 328e287f506..7ddc8dbe91e 100644 --- a/init.js +++ b/init.js @@ -2,8 +2,26 @@ const path = require('path') const Module = require('module') +const telemetry = require('./packages/dd-trace/src/telemetry/init-telemetry') +const semver = require('semver') + +function isTrue (envVar) { + return ['1', 'true', 'True'].includes(envVar) +} + +// eslint-disable-next-line no-console +let log = { info: isTrue(process.env.DD_TRACE_DEBUG) ? console.log : () => {} } +if (semver.satisfies(process.versions.node, '>=16')) { + const Config = require('./packages/dd-trace/src/config') + log = require('./packages/dd-trace/src/log') + + // eslint-disable-next-line no-new + new Config() // we need this to initialize the logger +} let initBailout = false +let clobberBailout = false +const forced = isTrue(process.env.DD_INJECT_FORCE) if (process.env.DD_INJECTION_ENABLED) { // If we're running via single-step install, and we're not in the app's @@ -19,13 +37,34 @@ if (process.env.DD_INJECTION_ENABLED) { if (resolvedInApp) { const ourselves = path.join(__dirname, 'index.js') if (ourselves !== resolvedInApp) { + clobberBailout = true + } + } + + // If we're running via single-step install, and the runtime doesn't match + // the engines field in package.json, then we should not initialize the tracer. + if (!clobberBailout) { + const { engines } = require('./package.json') + const version = process.versions.node + if (!semver.satisfies(version, engines.node)) { initBailout = true + telemetry([ + { name: 'abort', tags: ['reason:incompatible_runtime'] }, + { name: 'abort.runtime', tags: [] } + ]) + log.info('Aborting application instrumentation due to incompatible_runtime.') + log.info(`Found incompatible runtime nodejs ${version}, Supported runtimes: nodejs ${engines.node}.`) + if (forced) { + log.info('DD_INJECT_FORCE enabled, allowing unsupported runtimes and continuing.') + } } } } -if (!initBailout) { +if (!clobberBailout && (!initBailout || forced)) { const tracer = require('.') tracer.init() module.exports = tracer + telemetry('complete', [`injection_forced:${forced && initBailout ? 'true' : 'false'}`]) + log.info('Application instrumentation bootstrapping complete') } diff --git a/initialize.mjs b/initialize.mjs index e7b33de492b..777f45cc046 100644 --- a/initialize.mjs +++ b/initialize.mjs @@ -44,9 +44,12 @@ export async function getSource (...args) { } if (isMainThread) { - await import('./init.js') - const { register } = await import('node:module') - if (register) { - register('./loader-hook.mjs', import.meta.url) - } + // Need this IIFE for versions of Node.js without top-level await. + (async () => { + await import('./init.js') + const { register } = await import('node:module') + if (register) { + register('./loader-hook.mjs', import.meta.url) + } + })() } diff --git a/integration-tests/helpers.js b/integration-tests/helpers.js index b80fe4a4e28..98695c60156 100644 --- a/integration-tests/helpers.js +++ b/integration-tests/helpers.js @@ -7,15 +7,16 @@ const msgpack = require('msgpack-lite') const codec = msgpack.createCodec({ int64: true }) const EventEmitter = require('events') const childProcess = require('child_process') -const { fork } = childProcess +const { fork, spawn } = childProcess const exec = promisify(childProcess.exec) const http = require('http') -const fs = require('fs/promises') +const fs = require('fs') const os = require('os') const path = require('path') const rimraf = promisify(require('rimraf')) const id = require('../packages/dd-trace/src/id') const upload = require('multer')() +const assert = require('assert') const hookFile = 'dd-trace/loader-hook.mjs' @@ -162,6 +163,95 @@ class FakeAgent extends EventEmitter { } } +async function runAndCheckOutput (filename, cwd, expectedOut) { + const proc = spawn('node', [filename], { cwd, stdio: 'pipe' }) + const pid = proc.pid + let out = await new Promise((resolve, reject) => { + proc.on('error', reject) + let out = Buffer.alloc(0) + proc.stdout.on('data', data => { + out = Buffer.concat([out, data]) + }) + proc.stderr.pipe(process.stdout) + proc.on('exit', () => resolve(out.toString('utf8'))) + setTimeout(() => { + if (proc.exitCode === null) proc.kill() + }, 1000) // TODO this introduces flakiness. find a better way to end the process. + }) + if (typeof expectedOut === 'function') { + expectedOut(out) + } else { + if (process.env.DD_TRACE_DEBUG) { + // Debug adds this, which we don't care about in these tests + out = out.replace('Flushing 0 metrics via HTTP\n', '') + } + assert.strictEqual(out, expectedOut) + } + return pid +} + +// This is set by the useSandbox function +let sandbox + +// This _must_ be used with the useSandbox function +async function runAndCheckWithTelemetry (filename, expectedOut, ...expectedTelemetryPoints) { + const cwd = sandbox.folder + const cleanup = telemetryForwarder(expectedTelemetryPoints) + const pid = await runAndCheckOutput(filename, cwd, expectedOut) + const msgs = await cleanup() + if (expectedTelemetryPoints.length === 0) { + // assert no telemetry sent + try { + assert.deepStrictEqual(msgs.length, 0) + } catch (e) { + // This console.log is useful for debugging telemetry. Plz don't remove. + // eslint-disable-next-line no-console + console.error('Expected no telemetry, but got:\n', msgs.map(msg => JSON.stringify(msg[1].points)).join('\n')) + throw e + } + return + } + let points = [] + for (const [telemetryType, data] of msgs) { + assert.strictEqual(telemetryType, 'library_entrypoint') + assert.deepStrictEqual(data.metadata, meta(pid)) + points = points.concat(data.points) + } + let expectedPoints = getPoints(...expectedTelemetryPoints) + // We now have to sort both the expected and actual telemetry points. + // This is because data can come in in any order. + // We'll just contatenate all the data together for each point and sort them. + points = points.map(p => p.name + '\t' + p.tags.join(',')).sort().join('\n') + expectedPoints = expectedPoints.map(p => p.name + '\t' + p.tags.join(',')).sort().join('\n') + assert.strictEqual(points, expectedPoints) + + function getPoints (...args) { + const expectedPoints = [] + let currentPoint = {} + for (const arg of args) { + if (!currentPoint.name) { + currentPoint.name = 'library_entrypoint.' + arg + } else { + currentPoint.tags = arg.split(',') + expectedPoints.push(currentPoint) + currentPoint = {} + } + } + return expectedPoints + } + + function meta (pid) { + return { + language_name: 'nodejs', + language_version: process.versions.node, + runtime_name: 'nodejs', + runtime_version: process.versions.node, + tracer_version: require('../package.json').version, + pid: Number(pid) + } + } +} + function spawnProc (filename, options = {}, stdioHandler) { const proc = fork(filename, { ...options, stdio: 'pipe' }) return new Promise((resolve, reject) => { @@ -205,9 +295,9 @@ async function createSandbox (dependencies = [], isGitRepo = false, // We might use NODE_OPTIONS to init the tracer. We don't want this to affect this operations const { NODE_OPTIONS, ...restOfEnv } = process.env - await fs.mkdir(folder) - await exec(`yarn pack --filename ${out}`) // TODO: cache this - await exec(`yarn add ${allDependencies.join(' ')}`, { cwd: folder, env: restOfEnv }) + fs.mkdirSync(folder) + await exec(`yarn pack --filename ${out}`, { env: restOfEnv }) // TODO: cache this + await exec(`yarn add ${allDependencies.join(' ')} --ignore-engines`, { cwd: folder, env: restOfEnv }) for (const path of integrationTestsPaths) { if (process.platform === 'win32') { @@ -229,7 +319,7 @@ async function createSandbox (dependencies = [], isGitRepo = false, if (isGitRepo) { await exec('git init', { cwd: folder }) - await fs.writeFile(path.join(folder, '.gitignore'), 'node_modules/', { flush: true }) + fs.writeFileSync(path.join(folder, '.gitignore'), 'node_modules/', { flush: true }) await exec('git config user.email "john@doe.com"', { cwd: folder }) await exec('git config user.name "John Doe"', { cwd: folder }) await exec('git config commit.gpgsign false', { cwd: folder }) @@ -245,6 +335,54 @@ async function createSandbox (dependencies = [], isGitRepo = false, } } +function telemetryForwarder (expectedTelemetryPoints) { + process.env.DD_TELEMETRY_FORWARDER_PATH = + path.join(__dirname, 'telemetry-forwarder.sh') + process.env.FORWARDER_OUT = path.join(__dirname, `forwarder-${Date.now()}.out`) + + let retries = 0 + + const tryAgain = async function () { + retries += 1 + await new Promise(resolve => setTimeout(resolve, 100)) + return cleanup() + } + + const cleanup = function () { + let msgs + try { + msgs = fs.readFileSync(process.env.FORWARDER_OUT, 'utf8').trim().split('\n') + } catch (e) { + if (expectedTelemetryPoints.length && e.code === 'ENOENT' && retries < 10) { + return tryAgain() + } + return [] + } + for (let i = 0; i < msgs.length; i++) { + const [telemetryType, data] = msgs[i].split('\t') + if (!data && retries < 10) { + return tryAgain() + } + let parsed + try { + parsed = JSON.parse(data) + } catch (e) { + if (!data && retries < 10) { + return tryAgain() + } + throw new SyntaxError(`error parsing data: ${e.message}\n${data}`) + } + msgs[i] = [telemetryType, parsed] + } + fs.unlinkSync(process.env.FORWARDER_OUT) + delete process.env.FORWARDER_OUT + delete process.env.DD_TELEMETRY_FORWARDER_PATH + return msgs + } + + return cleanup +} + async function curl (url, useHttp2 = false) { if (typeof url === 'object') { if (url.then) { @@ -313,14 +451,43 @@ async function spawnPluginIntegrationTestProc (cwd, serverFile, agentPort, stdio }, stdioHandler) } +function useEnv (env) { + before(() => { + Object.assign(process.env, env) + }) + after(() => { + for (const key of Object.keys(env)) { + delete process.env[key] + } + }) +} + +function useSandbox (...args) { + before(async () => { + sandbox = await createSandbox(...args) + }) + after(() => { + const oldSandbox = sandbox + sandbox = undefined + return oldSandbox.remove() + }) +} +function sandboxCwd () { + return sandbox.folder +} + module.exports = { FakeAgent, spawnProc, + runAndCheckWithTelemetry, createSandbox, curl, curlAndAssertMessage, getCiVisAgentlessConfig, getCiVisEvpProxyConfig, checkSpansForServiceName, - spawnPluginIntegrationTestProc + spawnPluginIntegrationTestProc, + useEnv, + useSandbox, + sandboxCwd } diff --git a/integration-tests/init.spec.js b/integration-tests/init.spec.js index f90968fc8c6..e61237311b8 100644 --- a/integration-tests/init.spec.js +++ b/integration-tests/init.spec.js @@ -1,107 +1,177 @@ +const semver = require('semver') const { - createSandbox, - spawnProc + runAndCheckWithTelemetry: testFile, + useEnv, + useSandbox, + sandboxCwd } = require('./helpers') -const { assert } = require('chai') const path = require('path') +const fs = require('fs') const DD_INJECTION_ENABLED = 'tracing' +const DD_INJECT_FORCE = 'true' +const DD_TRACE_DEBUG = 'true' -let cwd, proc, sandbox +const telemetryAbort = ['abort', 'reason:incompatible_runtime', 'abort.runtime', ''] +const telemetryForced = ['complete', 'injection_forced:true'] +const telemetryGood = ['complete', 'injection_forced:false'] -async function runTest (cwd, file, env, expected) { - return new Promise((resolve, reject) => { - spawnProc(path.join(cwd, file), { cwd, env, silent: true }, data => { - try { - assert.strictEqual(data.toString(), expected) - resolve() - } catch (e) { - reject(e) - } - }).then(subproc => { - proc = subproc - }) - }) -} +const { engines } = require('../package.json') +const supportedRange = engines.node +const currentVersionIsSupported = semver.satisfies(process.versions.node, supportedRange) function testInjectionScenarios (arg, filename, esmWorks = false) { - context('when dd-trace is not in the app dir', () => { - const NODE_OPTIONS = `--no-warnings --${arg} ${path.join(__dirname, '..', filename)}` - it('should initialize the tracer, if no DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/trace.js', { NODE_OPTIONS }, 'true\n') - }) - it('should not initialize the tracer, if DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/trace.js', { NODE_OPTIONS, DD_INJECTION_ENABLED }, 'false\n') - }) - it('should initialize instrumentation, if no DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/instrument.js', { NODE_OPTIONS }, 'true\n') - }) - it('should not initialize instrumentation, if DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/instrument.js', { NODE_OPTIONS, DD_INJECTION_ENABLED }, 'false\n') - }) - it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation, if no DD_INJECTION_ENABLED`, () => { - return runTest(cwd, 'init/instrument.mjs', { NODE_OPTIONS }, `${esmWorks}\n`) + if (!currentVersionIsSupported) return + const doTest = (file, ...args) => testFile(file, ...args) + context('preferring app-dir dd-trace', () => { + context('when dd-trace is not in the app dir', () => { + const NODE_OPTIONS = `--no-warnings --${arg} ${path.join(__dirname, '..', filename)}` + useEnv({ NODE_OPTIONS }) + + context('without DD_INJECTION_ENABLED', () => { + it('should initialize the tracer', () => doTest('init/trace.js', 'true\n')) + it('should initialize instrumentation', () => doTest('init/instrument.js', 'true\n')) + it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation`, () => + doTest('init/instrument.mjs', `${esmWorks}\n`)) + }) + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + + it('should not initialize the tracer', () => doTest('init/trace.js', 'false\n')) + it('should not initialize instrumentation', () => doTest('init/instrument.js', 'false\n')) + it('should not initialize ESM instrumentation', () => doTest('init/instrument.mjs', 'false\n')) + }) }) - it('should not initialize ESM instrumentation, if DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/instrument.mjs', { NODE_OPTIONS, DD_INJECTION_ENABLED }, 'false\n') + context('when dd-trace in the app dir', () => { + const NODE_OPTIONS = `--no-warnings --${arg} dd-trace/${filename}` + useEnv({ NODE_OPTIONS }) + + context('without DD_INJECTION_ENABLED', () => { + it('should initialize the tracer', () => doTest('init/trace.js', 'true\n')) + it('should initialize instrumentation', () => doTest('init/instrument.js', 'true\n')) + it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation`, () => + doTest('init/instrument.mjs', `${esmWorks}\n`)) + }) + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + + it('should initialize the tracer', () => doTest('init/trace.js', 'true\n', ...telemetryGood)) + it('should initialize instrumentation', () => doTest('init/instrument.js', 'true\n', ...telemetryGood)) + it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation`, () => + doTest('init/instrument.mjs', `${esmWorks}\n`, ...telemetryGood)) + }) }) }) - context('when dd-trace in the app dir', () => { - const NODE_OPTIONS = `--no-warnings --${arg} dd-trace/${filename}` - it('should initialize the tracer, if no DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/trace.js', { NODE_OPTIONS }, 'true\n') - }) - it('should initialize the tracer, if DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/trace.js', { NODE_OPTIONS, DD_INJECTION_ENABLED }, 'true\n') - }) - it('should initialize instrumentation, if no DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/instrument.js', { NODE_OPTIONS }, 'true\n') - }) - it('should initialize instrumentation, if DD_INJECTION_ENABLED', () => { - return runTest(cwd, 'init/instrument.js', { NODE_OPTIONS, DD_INJECTION_ENABLED }, 'true\n') - }) - it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation, if no DD_INJECTION_ENABLED`, () => { - return runTest(cwd, 'init/instrument.mjs', { NODE_OPTIONS }, `${esmWorks}\n`) - }) - it(`should ${esmWorks ? '' : 'not '}initialize ESM instrumentation, if DD_INJECTION_ENABLED`, () => { - return runTest(cwd, 'init/instrument.mjs', { NODE_OPTIONS, DD_INJECTION_ENABLED }, `${esmWorks}\n`) - }) +} + +function testRuntimeVersionChecks (arg, filename) { + context('runtime version check', () => { + const NODE_OPTIONS = `--${arg} dd-trace/${filename}` + const doTest = (...args) => testFile('init/trace.js', ...args) + const doTestForced = async (...args) => { + Object.assign(process.env, { DD_INJECT_FORCE }) + try { + await testFile('init/trace.js', ...args) + } finally { + delete process.env.DD_INJECT_FORCE + } + } + + if (!currentVersionIsSupported) { + context('when node version is less than engines field', () => { + useEnv({ NODE_OPTIONS }) + + it('should initialize the tracer, if no DD_INJECTION_ENABLED', () => + doTest('true\n')) + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + + context('without debug', () => { + it('should not initialize the tracer', () => doTest('false\n', ...telemetryAbort)) + it('should initialize the tracer, if DD_INJECT_FORCE', () => doTestForced('true\n', ...telemetryForced)) + }) + context('with debug', () => { + useEnv({ DD_TRACE_DEBUG }) + + it('should not initialize the tracer', () => + doTest(`Aborting application instrumentation due to incompatible_runtime. +Found incompatible runtime nodejs ${process.versions.node}, Supported runtimes: nodejs >=18. +false +`, ...telemetryAbort)) + it('should initialize the tracer, if DD_INJECT_FORCE', () => + doTestForced(`Aborting application instrumentation due to incompatible_runtime. +Found incompatible runtime nodejs ${process.versions.node}, Supported runtimes: nodejs >=18. +DD_INJECT_FORCE enabled, allowing unsupported runtimes and continuing. +Application instrumentation bootstrapping complete +true +`, ...telemetryForced)) + }) + }) + }) + } else { + context('when node version is more than engines field', () => { + useEnv({ NODE_OPTIONS }) + + it('should initialize the tracer, if no DD_INJECTION_ENABLED', () => doTest('true\n')) + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + + context('without debug', () => { + it('should initialize the tracer', () => doTest('true\n', ...telemetryGood)) + it('should initialize the tracer, if DD_INJECT_FORCE', () => + doTestForced('true\n', ...telemetryGood)) + }) + context('with debug', () => { + useEnv({ DD_TRACE_DEBUG }) + + it('should initialize the tracer', () => + doTest('Application instrumentation bootstrapping complete\ntrue\n', ...telemetryGood)) + it('should initialize the tracer, if DD_INJECT_FORCE', () => + doTestForced('Application instrumentation bootstrapping complete\ntrue\n', ...telemetryGood)) + }) + }) + }) + } }) } +function stubTracerIfNeeded () { + if (!currentVersionIsSupported) { + before(() => { + // Stub out the tracer in the sandbox, since it will not likely load properly. + // We're only doing this on versions we don't support, since the forcing + // action results in undefined behavior in the tracer. + fs.writeFileSync( + path.join(sandboxCwd(), 'node_modules/dd-trace/index.js'), + 'exports.init = () => { Object.assign(global, { _ddtrace: true }) }' + ) + }) + } +} + describe('init.js', () => { - before(async () => { - sandbox = await createSandbox() - cwd = sandbox.folder - }) - afterEach(() => { - proc && proc.kill() - }) - after(() => { - return sandbox.remove() - }) + useSandbox() + stubTracerIfNeeded() testInjectionScenarios('require', 'init.js', false) + testRuntimeVersionChecks('require', 'init.js') }) -describe('initialize.mjs', () => { - before(async () => { - sandbox = await createSandbox() - cwd = sandbox.folder - }) - afterEach(() => { - proc && proc.kill() - }) - after(() => { - return sandbox.remove() - }) +// ESM is not supportable prior to Node.js 12 +if (semver.satisfies(process.versions.node, '>=12')) { + describe('initialize.mjs', () => { + useSandbox() + stubTracerIfNeeded() - context('as --loader', () => { - testInjectionScenarios('loader', 'initialize.mjs', true) - }) - if (Number(process.versions.node.split('.')[0]) >= 18) { - context('as --import', () => { - testInjectionScenarios('import', 'initialize.mjs', true) + context('as --loader', () => { + testInjectionScenarios('loader', 'initialize.mjs', true) + testRuntimeVersionChecks('loader', 'initialize.mjs') }) - } -}) + if (Number(process.versions.node.split('.')[0]) >= 18) { + context('as --import', () => { + testInjectionScenarios('import', 'initialize.mjs', true) + testRuntimeVersionChecks('loader', 'initialize.mjs') + }) + } + }) +} diff --git a/integration-tests/package-guardrails.spec.js b/integration-tests/package-guardrails.spec.js new file mode 100644 index 00000000000..8fff27db3b2 --- /dev/null +++ b/integration-tests/package-guardrails.spec.js @@ -0,0 +1,95 @@ +const { + runAndCheckWithTelemetry: testFile, + useEnv, + useSandbox, + sandboxCwd +} = require('./helpers') +const path = require('path') +const fs = require('fs') +const assert = require('assert') + +const NODE_OPTIONS = '--require dd-trace/init.js' +const DD_TRACE_DEBUG = 'true' +const DD_INJECTION_ENABLED = 'tracing' +const DD_LOG_LEVEL = 'error' + +describe('package guardrails', () => { + useEnv({ NODE_OPTIONS }) + const runTest = (...args) => + testFile('package-guardrails/index.js', ...args) + + context('when package is out of range', () => { + useSandbox(['bluebird@1.0.0']) + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + it('should not instrument the package, and send telemetry', () => + runTest('false\n', + 'complete', 'injection_forced:false', + 'abort.integration', 'integration:bluebird,integration_version:1.0.0' + )) + }) + context('with logging disabled', () => { + it('should not instrument the package', () => runTest('false\n')) + }) + context('with logging enabled', () => { + useEnv({ DD_TRACE_DEBUG }) + it('should not instrument the package', () => + runTest(`Application instrumentation bootstrapping complete +Found incompatible integration version: bluebird@1.0.0 +false +`)) + }) + }) + + context('when package is in range', () => { + context('when bluebird is 2.9.0', () => { + useSandbox(['bluebird@2.9.0']) + it('should instrument the package', () => runTest('true\n')) + }) + context('when bluebird is 3.7.2', () => { + useSandbox(['bluebird@3.7.2']) + it('should instrument the package', () => runTest('true\n')) + }) + }) + + context('when package errors out', () => { + useSandbox(['bluebird']) + before(() => { + const file = path.join(sandboxCwd(), 'node_modules/dd-trace/packages/datadog-instrumentations/src/bluebird.js') + fs.writeFileSync(file, ` +const { addHook } = require('./helpers/instrument') + +addHook({ name: 'bluebird', versions: ['*'] }, Promise => { + throw new ReferenceError('this is a test error') + return Promise +}) + `) + }) + + context('with DD_INJECTION_ENABLED', () => { + useEnv({ DD_INJECTION_ENABLED }) + it('should not instrument the package, and send telemetry', () => + runTest('false\n', + 'complete', 'injection_forced:false', + 'error', 'error_type:ReferenceError,integration:bluebird,integration_version:3.7.2' + )) + }) + + context('with logging disabled', () => { + it('should not instrument the package', () => runTest('false\n')) + }) + + context('with logging enabled', () => { + useEnv({ DD_TRACE_DEBUG, DD_LOG_LEVEL }) + it('should not instrument the package', () => + runTest( + log => { + assert.ok(log.includes(` +Error during ddtrace instrumentation of application, aborting. +ReferenceError: this is a test error + at `)) + assert.ok(log.includes('\nfalse\n')) + })) + }) + }) +}) diff --git a/integration-tests/package-guardrails/index.js b/integration-tests/package-guardrails/index.js new file mode 100644 index 00000000000..efaf37abcd8 --- /dev/null +++ b/integration-tests/package-guardrails/index.js @@ -0,0 +1,8 @@ +'use strict' + +const P = require('bluebird') + +const isWrapped = P.prototype._then.toString().includes('AsyncResource') + +// eslint-disable-next-line no-console +console.log(isWrapped) diff --git a/integration-tests/telemetry-forwarder.sh b/integration-tests/telemetry-forwarder.sh new file mode 100755 index 00000000000..5fe156993be --- /dev/null +++ b/integration-tests/telemetry-forwarder.sh @@ -0,0 +1,7 @@ +#!/usr/bin/env bash + +# Implemented this in bash instead of Node.js for two reasons: +# 1. It's trivial in bash. +# 2. We're using NODE_OPTIONS in tests to init the tracer, and we don't want that for this script. + +echo "$1 $(cat -)" >> $FORWARDER_OUT diff --git a/packages/datadog-instrumentations/src/helpers/register.js b/packages/datadog-instrumentations/src/helpers/register.js index eba90d6a980..2850664c8e2 100644 --- a/packages/datadog-instrumentations/src/helpers/register.js +++ b/packages/datadog-instrumentations/src/helpers/register.js @@ -7,6 +7,7 @@ const Hook = require('./hook') const requirePackageJson = require('../../../dd-trace/src/require-package-json') const log = require('../../../dd-trace/src/log') const checkRequireCache = require('../check_require_cache') +const telemetry = require('../../../dd-trace/src/telemetry/init-telemetry') const { DD_TRACE_DISABLED_INSTRUMENTATIONS = '', @@ -35,6 +36,8 @@ if (DD_TRACE_DEBUG && DD_TRACE_DEBUG.toLowerCase() !== 'false') { setImmediate(checkRequireCache.checkForPotentialConflicts) } +const seenCombo = new Set() + // TODO: make this more efficient for (const packageName of names) { if (disabledInstrumentations.has(packageName)) continue @@ -49,6 +52,7 @@ for (const packageName of names) { return moduleExports } + const namesAndSuccesses = {} for (const { name, file, versions, hook } of instrumentations[packageName]) { const fullFilename = filename(name, file) @@ -61,10 +65,17 @@ for (const packageName of names) { if (moduleName === fullFilename) { const version = moduleVersion || getVersion(moduleBaseDir) + if (!Object.hasOwnProperty(namesAndSuccesses, name)) { + namesAndSuccesses[name] = { + success: false, + version + } + } if (matchVersion(version, versions)) { // Check if the hook already has a set moduleExport if (hook[HOOK_SYMBOL].has(moduleExports)) { + namesAndSuccesses[name].success = true return moduleExports } @@ -76,11 +87,29 @@ for (const packageName of names) { // Set the moduleExports in the hooks weakmap hook[HOOK_SYMBOL].set(moduleExports, name) } catch (e) { - log.error(e) + log.info('Error during ddtrace instrumentation of application, aborting.') + log.info(e) + telemetry('error', [ + `error_type:${e.constructor.name}`, + `integration:${name}`, + `integration_version:${version}` + ]) } + namesAndSuccesses[name].success = true } } } + for (const name of Object.keys(namesAndSuccesses)) { + const { success, version } = namesAndSuccesses[name] + if (!success && !seenCombo.has(`${name}@${version}`)) { + telemetry('abort.integration', [ + `integration:${name}`, + `integration_version:${version}` + ]) + log.info(`Found incompatible integration version: ${name}@${version}`) + seenCombo.add(`${name}@${version}`) + } + } return moduleExports }) diff --git a/packages/dd-trace/src/telemetry/init-telemetry.js b/packages/dd-trace/src/telemetry/init-telemetry.js new file mode 100644 index 00000000000..a126ecc6238 --- /dev/null +++ b/packages/dd-trace/src/telemetry/init-telemetry.js @@ -0,0 +1,75 @@ +'use strict' + +const fs = require('fs') +const { spawn } = require('child_process') +const tracerVersion = require('../../../../package.json').version +const log = require('../log') + +module.exports = sendTelemetry + +if (!process.env.DD_INJECTION_ENABLED) { + module.exports = () => {} +} + +if (!process.env.DD_TELEMETRY_FORWARDER_PATH) { + module.exports = () => {} +} + +if (!fs.existsSync(process.env.DD_TELEMETRY_FORWARDER_PATH)) { + module.exports = () => {} +} + +const metadata = { + language_name: 'nodejs', + language_version: process.versions.node, + runtime_name: 'nodejs', + runtime_version: process.versions.node, + tracer_version: tracerVersion, + pid: process.pid +} + +const seen = [] +function hasSeen (point) { + if (point.name === 'abort') { + // This one can only be sent once, regardless of tags + return seen.includes('abort') + } + if (point.name === 'abort.integration') { + // For now, this is the only other one we want to dedupe + const compiledPoint = point.name + point.tags.join('') + return seen.includes(compiledPoint) + } + return false +} + +function sendTelemetry (name, tags = []) { + let points = name + if (typeof name === 'string') { + points = [{ name, tags }] + } + if (['1', 'true', 'True'].includes(process.env.DD_INJECT_FORCE)) { + points = points.filter(p => ['error', 'complete'].includes(p.name)) + } + points = points.filter(p => !hasSeen(p)) + points.forEach(p => { + p.name = `library_entrypoint.${p.name}` + }) + if (points.length === 0) { + return + } + const proc = spawn(process.env.DD_TELEMETRY_FORWARDER_PATH, ['library_entrypoint'], { + stdio: 'pipe' + }) + proc.on('error', () => { + log.error('Failed to spawn telemetry forwarder') + }) + proc.on('exit', (code) => { + if (code !== 0) { + log.error(`Telemetry forwarder exited with code ${code}`) + } + }) + proc.stdin.on('error', () => { + log.error('Failed to write telemetry data to telemetry forwarder') + }) + proc.stdin.end(JSON.stringify({ metadata, points })) +}