From 5311183a66fd8d568ec1d5e019b9f1202f886db8 Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Thu, 6 Aug 2026 12:38:16 -0700 Subject: [PATCH 1/6] Refactor `child_process` instrumentation to use tracing channel instead of `Shim` --- lib/instrumentation/core/child_process.js | 109 ++++++++++++++++++---- 1 file changed, 91 insertions(+), 18 deletions(-) diff --git a/lib/instrumentation/core/child_process.js b/lib/instrumentation/core/child_process.js index f49bb89c00..e3c1b91658 100644 --- a/lib/instrumentation/core/child_process.js +++ b/lib/instrumentation/core/child_process.js @@ -5,33 +5,106 @@ 'use strict' -const { RecorderSpec } = require('../../../lib/shim/specs') +// eslint-disable-next-line n/no-unsupported-features/node-builtins +const { tracingChannel } = require('node:diagnostics_channel') + +// Create channels based on instrumented methods +const METHODS = ['exec', 'execFile'] +const channels = new Map(METHODS.map((name) => [name, tracingChannel('child_process.' + name)])) + +// Patched once per process and never unwrapped; each `initialize()` call +// just re-points the bound store at the current agent. +let patched = false +let currentTracer = null +let boundStore = null module.exports = initialize -function initialize(agent, childProcess, moduleName, shim) { - if (!childProcess) { - shim.logger.debug('Could not find child_process, not instrumenting') - return false +function initialize(agent, childProcess) { + patch(childProcess) + rebindStore(agent) +} + +function patch(childProcess) { + if (patched === true) { + return } + patched = true - const methods = ['exec', 'execFile'] + for (const [methodName, channel] of channels) { + const original = childProcess[methodName] - shim.record(childProcess, methods, function recordExec(shim, fn, name) { - return new RecorderSpec({ name: 'child_process.' + name, callback: shim.LAST }) - }) + childProcess[methodName] = function wrappedMethod(...args) { + const ctx = currentTracer?.getContext() + if (!ctx?.transaction?.isActive()) { + return original.apply(this, args) + } - makePromisifyCompatible(shim, childProcess) -} + const lastArg = args[args.length - 1] + const hasCallback = typeof lastArg === 'function' + const data = { methodName, callbackName: hasCallback ? lastArg.name || '' : null } + + return hasCallback + ? channel.traceCallback(original, -1, data, this, ...args) + : channel.traceSync(original, data, this, ...args) + } -function makePromisifyCompatible(shim, childProcess) { - const originalExec = shim.getOriginal(childProcess.exec) - for (const symbol of Object.getOwnPropertySymbols(originalExec)) { - childProcess.exec[symbol] = originalExec[symbol] + for (const symbol of Object.getOwnPropertySymbols(original)) { + childProcess[methodName][symbol] = original[symbol] + } + } +} +// TODO: This can be repurposed for other core instrumentation +// refactors over to tracing channel. +function createSegment(tracer, ctx, name) { + const segment = tracer.createSegment({ name, parent: ctx?.segment, transaction: ctx?.transaction }) + if (segment) { + segment.start() } + return segment +} + +function rebindStore(agent) { + const tracer = agent.tracer + const store = tracer._contextManager._asyncLocalStorage + + for (const channel of channels.values()) { + if (boundStore && boundStore !== store) { + channel.start.unbindStore(boundStore) + channel.asyncStart.unbindStore(boundStore) + } + + channel.start.bindStore(store, (data) => { + const ctx = tracer.getContext() + const segment = createSegment(tracer, ctx, 'child_process.' + data.methodName) + data.ctx = segment ? ctx.enterSegment({ segment }) : ctx + return data.ctx + }) + + channel.asyncStart.bindStore(store, (data) => { + const ctx = data.ctx + ctx.segment.touch() - const originalExecFile = shim.getOriginal(childProcess.execFile) - for (const symbol of Object.getOwnPropertySymbols(originalExecFile)) { - childProcess.execFile[symbol] = originalExecFile[symbol] + const callbackSegment = createSegment(tracer, ctx, 'Callback: ' + data.callbackName) + data.callbackSegment = callbackSegment + return ctx.enterSegment({ segment: callbackSegment }) + }) } + + boundStore = store + currentTracer = tracer +} + +// `end`/`asyncEnd` run once at module load and don't need +// agent.tracer (segment is already created within `data`), +// while `start`/`asyncStart` are handled inside rebindStore(). +for (const channel of channels.values()) { + channel.subscribe({ + end(data) { + data.ctx?.segment?.touch() + }, + asyncEnd(data) { + data.callbackSegment?.touch() + } + }) } From 2ef6c25e7c47e8f51843be1ed4970fa38ebc548e Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Mon, 10 Aug 2026 10:10:06 -0700 Subject: [PATCH 2/6] Add unit test if no `child_process` --- lib/instrumentation/core/child_process.js | 10 ++++-- .../core/child_process.test.js | 33 +++++++++++++++++++ 2 files changed, 41 insertions(+), 2 deletions(-) create mode 100644 test/unit/instrumentation/core/child_process.test.js diff --git a/lib/instrumentation/core/child_process.js b/lib/instrumentation/core/child_process.js index e3c1b91658..0a97cbb195 100644 --- a/lib/instrumentation/core/child_process.js +++ b/lib/instrumentation/core/child_process.js @@ -7,10 +7,11 @@ // eslint-disable-next-line n/no-unsupported-features/node-builtins const { tracingChannel } = require('node:diagnostics_channel') +const logger = require('../../logger').child({ component: 'child_process' }) // Create channels based on instrumented methods -const METHODS = ['exec', 'execFile'] -const channels = new Map(METHODS.map((name) => [name, tracingChannel('child_process.' + name)])) +const methods = ['exec', 'execFile'] +const channels = new Map(methods.map((name) => [name, tracingChannel('child_process.' + name)])) // Patched once per process and never unwrapped; each `initialize()` call // just re-points the bound store at the current agent. @@ -21,6 +22,11 @@ let boundStore = null module.exports = initialize function initialize(agent, childProcess) { + if (!childProcess) { + logger.debug('Could not find child_process, not instrumenting') + return false + } + patch(childProcess) rebindStore(agent) } diff --git a/test/unit/instrumentation/core/child_process.test.js b/test/unit/instrumentation/core/child_process.test.js new file mode 100644 index 0000000000..8a18ff0b32 --- /dev/null +++ b/test/unit/instrumentation/core/child_process.test.js @@ -0,0 +1,33 @@ +/* + * Copyright 2020 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +const test = require('node:test') +const assert = require('node:assert') +const sinon = require('sinon') +const helper = require('#testlib/agent_helper.js') +const logger = require('#agentlib/logger.js') +const childProcessInstrumentation = require('#agentlib/instrumentation/core/child_process.js') + +test('child_process instrumentation', async (t) => { + const agent = helper.loadMockedAgent() + t.after(() => { + helper.unloadAgent(agent) + }) + + await t.test('should log and return false when child_process is not available', (t) => { + const proto = Object.getPrototypeOf(logger.child({})) + const debugStub = sinon.stub(proto, 'debug') + t.after(() => { + debugStub.restore() + }) + + const result = childProcessInstrumentation(agent, null) + + assert.equal(result, false) + assert.ok(debugStub.calledWith('Could not find child_process, not instrumenting')) + }) +}) From 5b832b5ab1bd75ad85e012467719d3d113460343 Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Mon, 10 Aug 2026 13:32:07 -0700 Subject: [PATCH 3/6] Address PR feedback: Refactor to `ChildProcessInstrumentation`; add double-wrapped test --- lib/instrumentation/core/child_process.js | 157 +++++++++--------- .../core/child_process.test.js | 33 ++-- 2 files changed, 102 insertions(+), 88 deletions(-) diff --git a/lib/instrumentation/core/child_process.js b/lib/instrumentation/core/child_process.js index 0a97cbb195..7a60d441ef 100644 --- a/lib/instrumentation/core/child_process.js +++ b/lib/instrumentation/core/child_process.js @@ -1,5 +1,5 @@ /* - * Copyright 2020 New Relic Corporation. All rights reserved. + * Copyright 2026 New Relic Corporation. All rights reserved. * SPDX-License-Identifier: Apache-2.0 */ @@ -7,104 +7,107 @@ // eslint-disable-next-line n/no-unsupported-features/node-builtins const { tracingChannel } = require('node:diagnostics_channel') -const logger = require('../../logger').child({ component: 'child_process' }) +const defaultLogger = require('#agentlib/logger.js').child({ component: 'child_process' }) -// Create channels based on instrumented methods -const methods = ['exec', 'execFile'] -const channels = new Map(methods.map((name) => [name, tracingChannel('child_process.' + name)])) - -// Patched once per process and never unwrapped; each `initialize()` call -// just re-points the bound store at the current agent. -let patched = false -let currentTracer = null -let boundStore = null +const symWrapped = Symbol('nr_wrapped') +const channels = { + exec: tracingChannel('child_process.exec'), + execFile: tracingChannel('child_process.execFile') +} -module.exports = initialize +class ChildProcessInstrumentation { + /** currently active `ChildProcessInstrumentation` instance */ + static #active = null -function initialize(agent, childProcess) { - if (!childProcess) { - logger.debug('Could not find child_process, not instrumenting') - return false + constructor(agent) { + this.tracer = agent.tracer + this.store = this.tracer._contextManager._asyncLocalStorage } - patch(childProcess) - rebindStore(agent) -} + patch(childProcess) { + for (const [methodName, channel] of Object.entries(channels)) { + const original = childProcess[methodName] + if (original[symWrapped] === true) continue -function patch(childProcess) { - if (patched === true) { - return - } - patched = true + childProcess[methodName] = function wrappedMethod(...args) { + const ctx = ChildProcessInstrumentation.#active?.tracer.getContext() + if (!ctx?.transaction?.isActive()) { + return original.apply(this, args) + } - for (const [methodName, channel] of channels) { - const original = childProcess[methodName] + const lastArg = args[args.length - 1] + const hasCallback = typeof lastArg === 'function' + const data = { methodName, callbackName: hasCallback ? lastArg.name || '' : null } - childProcess[methodName] = function wrappedMethod(...args) { - const ctx = currentTracer?.getContext() - if (!ctx?.transaction?.isActive()) { - return original.apply(this, args) + return hasCallback + ? channel.traceCallback(original, -1, data, this, ...args) + : channel.traceSync(original, data, this, ...args) } - const lastArg = args[args.length - 1] - const hasCallback = typeof lastArg === 'function' - const data = { methodName, callbackName: hasCallback ? lastArg.name || '' : null } - - return hasCallback - ? channel.traceCallback(original, -1, data, this, ...args) - : channel.traceSync(original, data, this, ...args) + for (const symbol of Object.getOwnPropertySymbols(original)) { + childProcess[methodName][symbol] = original[symbol] + } + childProcess[methodName][symWrapped] = true } + } - for (const symbol of Object.getOwnPropertySymbols(original)) { - childProcess[methodName][symbol] = original[symbol] + // TODO: this can be extracted to be used by other core instrumentation + // as we refactor them to use tracing channel + createSegment(ctx, name) { + const segment = this.tracer.createSegment({ name, parent: ctx?.segment, transaction: ctx?.transaction }) + if (segment) { + segment.start() } + return segment } -} -// TODO: This can be repurposed for other core instrumentation -// refactors over to tracing channel. -function createSegment(tracer, ctx, name) { - const segment = tracer.createSegment({ name, parent: ctx?.segment, transaction: ctx?.transaction }) - if (segment) { - segment.start() - } - return segment -} -function rebindStore(agent) { - const tracer = agent.tracer - const store = tracer._contextManager._asyncLocalStorage + rebindStore() { + const { tracer, store } = this + const previous = ChildProcessInstrumentation.#active - for (const channel of channels.values()) { - if (boundStore && boundStore !== store) { - channel.start.unbindStore(boundStore) - channel.asyncStart.unbindStore(boundStore) + for (const channel of Object.values(channels)) { + if (previous && previous.store !== store) { + channel.start.unbindStore(previous.store) + channel.asyncStart.unbindStore(previous.store) + } + + channel.start.bindStore(store, (data) => { + const ctx = tracer.getContext() + const segment = this.createSegment(ctx, 'child_process.' + data.methodName) + data.ctx = segment ? ctx.enterSegment({ segment }) : ctx + return data.ctx + }) + + channel.asyncStart.bindStore(store, (data) => { + const { ctx, callbackName } = data + ctx.segment.touch() + + const segment = this.createSegment(ctx, 'Callback: ' + callbackName) + data.callbackSegment = segment + return ctx.enterSegment({ segment }) + }) } - channel.start.bindStore(store, (data) => { - const ctx = tracer.getContext() - const segment = createSegment(tracer, ctx, 'child_process.' + data.methodName) - data.ctx = segment ? ctx.enterSegment({ segment }) : ctx - return data.ctx - }) - - channel.asyncStart.bindStore(store, (data) => { - const ctx = data.ctx - ctx.segment.touch() - - const callbackSegment = createSegment(tracer, ctx, 'Callback: ' + data.callbackName) - data.callbackSegment = callbackSegment - return ctx.enterSegment({ segment: callbackSegment }) - }) + ChildProcessInstrumentation.#active = this + } +} + +module.exports = function initialize(agent, childProcess, { logger = defaultLogger } = {}) { + if (!childProcess) { + logger.debug('Could not find child_process, not instrumenting') + return false } - boundStore = store - currentTracer = tracer + const instrumentation = new ChildProcessInstrumentation(agent) + instrumentation.patch(childProcess) + instrumentation.rebindStore() + return instrumentation } -// `end`/`asyncEnd` run once at module load and don't need -// agent.tracer (segment is already created within `data`), -// while `start`/`asyncStart` are handled inside rebindStore(). -for (const channel of channels.values()) { +// `end`/`asyncEnd` are agent-agnostic (operate only on what's already +// stashed on `data` by the bindStore transforms above), so unlike +// `start`/`asyncStart` they only ever need to be subscribed once. +for (const channel of Object.values(channels)) { channel.subscribe({ end(data) { data.ctx?.segment?.touch() diff --git a/test/unit/instrumentation/core/child_process.test.js b/test/unit/instrumentation/core/child_process.test.js index 8a18ff0b32..c3a14d4da2 100644 --- a/test/unit/instrumentation/core/child_process.test.js +++ b/test/unit/instrumentation/core/child_process.test.js @@ -1,5 +1,5 @@ /* - * Copyright 2020 New Relic Corporation. All rights reserved. + * Copyright 2026 New Relic Corporation. All rights reserved. * SPDX-License-Identifier: Apache-2.0 */ @@ -7,9 +7,7 @@ const test = require('node:test') const assert = require('node:assert') -const sinon = require('sinon') const helper = require('#testlib/agent_helper.js') -const logger = require('#agentlib/logger.js') const childProcessInstrumentation = require('#agentlib/instrumentation/core/child_process.js') test('child_process instrumentation', async (t) => { @@ -18,16 +16,29 @@ test('child_process instrumentation', async (t) => { helper.unloadAgent(agent) }) - await t.test('should log and return false when child_process is not available', (t) => { - const proto = Object.getPrototypeOf(logger.child({})) - const debugStub = sinon.stub(proto, 'debug') - t.after(() => { - debugStub.restore() - }) + await t.test('should log and return false when child_process is not available', () => { + const debugCalls = [] + const stubLogger = { debug: (msg) => debugCalls.push(msg) } - const result = childProcessInstrumentation(agent, null) + const result = childProcessInstrumentation(agent, null, { logger: stubLogger }) assert.equal(result, false) - assert.ok(debugStub.calledWith('Could not find child_process, not instrumenting')) + assert.deepEqual(debugCalls, ['Could not find child_process, not instrumenting']) + }) + + await t.test('should not re-wrap exec/execFile on repeated initialize calls', () => { + const fakeChildProcess = { + exec: function exec() {}, + execFile: function execFile() {} + } + + childProcessInstrumentation(agent, fakeChildProcess) + const wrappedExec = fakeChildProcess.exec + const wrappedExecFile = fakeChildProcess.execFile + + childProcessInstrumentation(agent, fakeChildProcess) + + assert.equal(fakeChildProcess.exec, wrappedExec, 'exec should not be wrapped a second time') + assert.equal(fakeChildProcess.execFile, wrappedExecFile, 'execFile should not be wrapped a second time') }) }) From ab569bad643e6e85c2c6ec98447f823b8cda898a Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Tue, 11 Aug 2026 08:10:19 -0700 Subject: [PATCH 4/6] Add proper teardown --- lib/instrumentation/core/child_process.js | 33 ++++++++++--------- lib/shimmer.js | 10 +++++- .../core/child_process.test.js | 33 ++++++++++++------- test/unit/shimmer.test.js | 11 +++++++ 4 files changed, 59 insertions(+), 28 deletions(-) diff --git a/lib/instrumentation/core/child_process.js b/lib/instrumentation/core/child_process.js index 7a60d441ef..46ec93fc98 100644 --- a/lib/instrumentation/core/child_process.js +++ b/lib/instrumentation/core/child_process.js @@ -9,28 +9,28 @@ const { tracingChannel } = require('node:diagnostics_channel') const defaultLogger = require('#agentlib/logger.js').child({ component: 'child_process' }) -const symWrapped = Symbol('nr_wrapped') const channels = { exec: tracingChannel('child_process.exec'), execFile: tracingChannel('child_process.execFile') } class ChildProcessInstrumentation { - /** currently active `ChildProcessInstrumentation` instance */ - static #active = null - constructor(agent) { this.tracer = agent.tracer this.store = this.tracer._contextManager._asyncLocalStorage + this.originals = {} } patch(childProcess) { + this.childProcess = childProcess + for (const [methodName, channel] of Object.entries(channels)) { const original = childProcess[methodName] - if (original[symWrapped] === true) continue + this.originals[methodName] = original + const tracer = this.tracer childProcess[methodName] = function wrappedMethod(...args) { - const ctx = ChildProcessInstrumentation.#active?.tracer.getContext() + const ctx = tracer.getContext() if (!ctx?.transaction?.isActive()) { return original.apply(this, args) } @@ -47,7 +47,6 @@ class ChildProcessInstrumentation { for (const symbol of Object.getOwnPropertySymbols(original)) { childProcess[methodName][symbol] = original[symbol] } - childProcess[methodName][symWrapped] = true } } @@ -61,16 +60,10 @@ class ChildProcessInstrumentation { return segment } - rebindStore() { + bindStore() { const { tracer, store } = this - const previous = ChildProcessInstrumentation.#active for (const channel of Object.values(channels)) { - if (previous && previous.store !== store) { - channel.start.unbindStore(previous.store) - channel.asyncStart.unbindStore(previous.store) - } - channel.start.bindStore(store, (data) => { const ctx = tracer.getContext() const segment = this.createSegment(ctx, 'child_process.' + data.methodName) @@ -87,8 +80,16 @@ class ChildProcessInstrumentation { return ctx.enterSegment({ segment }) }) } + } - ChildProcessInstrumentation.#active = this + teardown() { + for (const [methodName, channel] of Object.entries(channels)) { + if (this.originals[methodName]) { + this.childProcess[methodName] = this.originals[methodName] + } + channel.start.unbindStore(this.store) + channel.asyncStart.unbindStore(this.store) + } } } @@ -100,7 +101,7 @@ module.exports = function initialize(agent, childProcess, { logger = defaultLogg const instrumentation = new ChildProcessInstrumentation(agent) instrumentation.patch(childProcess) - instrumentation.rebindStore() + instrumentation.bindStore() return instrumentation } diff --git a/lib/shimmer.js b/lib/shimmer.js index 1e94f5da28..743615df0c 100644 --- a/lib/shimmer.js +++ b/lib/shimmer.js @@ -275,6 +275,8 @@ const shimmer = (module.exports = { registerCoreInstrumentation(agent) { instrumentProcessMethods(agent) + this._coreInstrumentations = {} + // Instrument each of the core modules. for (const [mojule, core] of Object.entries(CORE_INSTRUMENTATION)) { if (agent.config.instrumentation?.[mojule].enabled === false) { @@ -298,7 +300,7 @@ const shimmer = (module.exports = { resolvedName: mojule }) applyDebugState(shim, core, false) - _firstPartyInstrumentation(agent, filePath, shim, uninstrumented, mojule) + this._coreInstrumentations[mojule] = _firstPartyInstrumentation(agent, filePath, shim, uninstrumented, mojule) } } }, @@ -335,6 +337,12 @@ const shimmer = (module.exports = { if (this._subscribers) { shimmer.teardownSubscribers() } + if (this._coreInstrumentations) { + for (const instrumentation of Object.values(this._coreInstrumentations)) { + instrumentation?.teardown?.() + } + this._coreInstrumentations = {} + } if (this._modulePatch) { this._modulePatch.unpatch() } diff --git a/test/unit/instrumentation/core/child_process.test.js b/test/unit/instrumentation/core/child_process.test.js index c3a14d4da2..a290bdc5ad 100644 --- a/test/unit/instrumentation/core/child_process.test.js +++ b/test/unit/instrumentation/core/child_process.test.js @@ -26,19 +26,30 @@ test('child_process instrumentation', async (t) => { assert.deepEqual(debugCalls, ['Could not find child_process, not instrumenting']) }) - await t.test('should not re-wrap exec/execFile on repeated initialize calls', () => { - const fakeChildProcess = { - exec: function exec() {}, - execFile: function execFile() {} - } + await t.test('teardown should restore the original exec/execFile', () => { + const originalExec = function exec() {} + const originalExecFile = function execFile() {} + const fakeChildProcess = { exec: originalExec, execFile: originalExecFile } - childProcessInstrumentation(agent, fakeChildProcess) - const wrappedExec = fakeChildProcess.exec - const wrappedExecFile = fakeChildProcess.execFile + const instrumentation = childProcessInstrumentation(agent, fakeChildProcess) + assert.notEqual(fakeChildProcess.exec, originalExec, 'exec should be wrapped after patch') + assert.notEqual(fakeChildProcess.execFile, originalExecFile, 'execFile should be wrapped after patch') - childProcessInstrumentation(agent, fakeChildProcess) + instrumentation.teardown() - assert.equal(fakeChildProcess.exec, wrappedExec, 'exec should not be wrapped a second time') - assert.equal(fakeChildProcess.execFile, wrappedExecFile, 'execFile should not be wrapped a second time') + assert.equal(fakeChildProcess.exec, originalExec, 'exec should be restored after teardown') + assert.equal(fakeChildProcess.execFile, originalExecFile, 'execFile should be restored after teardown') + }) + + await t.test('should not double-wrap after a teardown/re-patch cycle', () => { + const originalExec = function exec() {} + const fakeChildProcess = { exec: originalExec, execFile: function execFile() {} } + + const first = childProcessInstrumentation(agent, fakeChildProcess) + first.teardown() + + const second = childProcessInstrumentation(agent, fakeChildProcess) + + assert.equal(second.originals.exec, originalExec, 'second patch should have wrapped the true original, not a stale wrapper') }) }) diff --git a/test/unit/shimmer.test.js b/test/unit/shimmer.test.js index 43f62dab06..641d55cb0d 100644 --- a/test/unit/shimmer.test.js +++ b/test/unit/shimmer.test.js @@ -719,6 +719,17 @@ test('should not throw if you call removeHooks before creating ritm and iitm hoo }) }) +test('should call teardown on core instrumentations that provide it when removeHooks runs', async () => { + const cp = require('child_process') + const originalExec = cp.exec + + const agent = helper.instrumentMockedAgent() + assert.notEqual(cp.exec, originalExec, 'exec should be wrapped after bootstrapping instrumentation') + + helper.unloadAgent(agent) + assert.equal(cp.exec, originalExec, 'exec should be restored to the original after removeHooks tears it down') +}) + test('Shimmer with logger mock', async (t) => { const sandbox = sinon.createSandbox() const loggerMock = require('./mocks/logger')(sandbox) From 1330ce04e101c7a1648765c24269d2739909e2a8 Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Tue, 11 Aug 2026 08:52:29 -0700 Subject: [PATCH 5/6] Refactor to use a new base subscriber, `tc-base` --- lib/core-instrumentation.js | 4 - lib/instrumentation/core/child_process.js | 120 ---------------- lib/shimmer.js | 10 +- lib/subscriber-configs.js | 1 + lib/subscribers/child_process/config.js | 14 ++ lib/subscribers/child_process/exec-file.js | 14 ++ lib/subscribers/child_process/exec.js | 69 +++++++++ lib/subscribers/tc-base.js | 133 ++++++++++++++++++ .../core/child_process.test.js | 55 -------- test/unit/shimmer.test.js | 11 -- .../subscribers/child_process/exec.test.js | 34 +++++ 11 files changed, 266 insertions(+), 199 deletions(-) delete mode 100644 lib/instrumentation/core/child_process.js create mode 100644 lib/subscribers/child_process/config.js create mode 100644 lib/subscribers/child_process/exec-file.js create mode 100644 lib/subscribers/child_process/exec.js create mode 100644 lib/subscribers/tc-base.js delete mode 100644 test/unit/instrumentation/core/child_process.test.js create mode 100644 test/unit/subscribers/child_process/exec.test.js diff --git a/lib/core-instrumentation.js b/lib/core-instrumentation.js index 7c04bdba2b..efc323905a 100644 --- a/lib/core-instrumentation.js +++ b/lib/core-instrumentation.js @@ -8,10 +8,6 @@ const InstrumentationDescriptor = require('./instrumentation-descriptor') module.exports = { - child_process: { - type: InstrumentationDescriptor.TYPE_GENERIC, - file: 'child_process.js' - }, crypto: { type: InstrumentationDescriptor.TYPE_GENERIC, file: 'crypto.js' diff --git a/lib/instrumentation/core/child_process.js b/lib/instrumentation/core/child_process.js deleted file mode 100644 index 46ec93fc98..0000000000 --- a/lib/instrumentation/core/child_process.js +++ /dev/null @@ -1,120 +0,0 @@ -/* - * Copyright 2026 New Relic Corporation. All rights reserved. - * SPDX-License-Identifier: Apache-2.0 - */ - -'use strict' - -// eslint-disable-next-line n/no-unsupported-features/node-builtins -const { tracingChannel } = require('node:diagnostics_channel') -const defaultLogger = require('#agentlib/logger.js').child({ component: 'child_process' }) - -const channels = { - exec: tracingChannel('child_process.exec'), - execFile: tracingChannel('child_process.execFile') -} - -class ChildProcessInstrumentation { - constructor(agent) { - this.tracer = agent.tracer - this.store = this.tracer._contextManager._asyncLocalStorage - this.originals = {} - } - - patch(childProcess) { - this.childProcess = childProcess - - for (const [methodName, channel] of Object.entries(channels)) { - const original = childProcess[methodName] - this.originals[methodName] = original - const tracer = this.tracer - - childProcess[methodName] = function wrappedMethod(...args) { - const ctx = tracer.getContext() - if (!ctx?.transaction?.isActive()) { - return original.apply(this, args) - } - - const lastArg = args[args.length - 1] - const hasCallback = typeof lastArg === 'function' - const data = { methodName, callbackName: hasCallback ? lastArg.name || '' : null } - - return hasCallback - ? channel.traceCallback(original, -1, data, this, ...args) - : channel.traceSync(original, data, this, ...args) - } - - for (const symbol of Object.getOwnPropertySymbols(original)) { - childProcess[methodName][symbol] = original[symbol] - } - } - } - - // TODO: this can be extracted to be used by other core instrumentation - // as we refactor them to use tracing channel - createSegment(ctx, name) { - const segment = this.tracer.createSegment({ name, parent: ctx?.segment, transaction: ctx?.transaction }) - if (segment) { - segment.start() - } - return segment - } - - bindStore() { - const { tracer, store } = this - - for (const channel of Object.values(channels)) { - channel.start.bindStore(store, (data) => { - const ctx = tracer.getContext() - const segment = this.createSegment(ctx, 'child_process.' + data.methodName) - data.ctx = segment ? ctx.enterSegment({ segment }) : ctx - return data.ctx - }) - - channel.asyncStart.bindStore(store, (data) => { - const { ctx, callbackName } = data - ctx.segment.touch() - - const segment = this.createSegment(ctx, 'Callback: ' + callbackName) - data.callbackSegment = segment - return ctx.enterSegment({ segment }) - }) - } - } - - teardown() { - for (const [methodName, channel] of Object.entries(channels)) { - if (this.originals[methodName]) { - this.childProcess[methodName] = this.originals[methodName] - } - channel.start.unbindStore(this.store) - channel.asyncStart.unbindStore(this.store) - } - } -} - -module.exports = function initialize(agent, childProcess, { logger = defaultLogger } = {}) { - if (!childProcess) { - logger.debug('Could not find child_process, not instrumenting') - return false - } - - const instrumentation = new ChildProcessInstrumentation(agent) - instrumentation.patch(childProcess) - instrumentation.bindStore() - return instrumentation -} - -// `end`/`asyncEnd` are agent-agnostic (operate only on what's already -// stashed on `data` by the bindStore transforms above), so unlike -// `start`/`asyncStart` they only ever need to be subscribed once. -for (const channel of Object.values(channels)) { - channel.subscribe({ - end(data) { - data.ctx?.segment?.touch() - }, - asyncEnd(data) { - data.callbackSegment?.touch() - } - }) -} diff --git a/lib/shimmer.js b/lib/shimmer.js index 743615df0c..1e94f5da28 100644 --- a/lib/shimmer.js +++ b/lib/shimmer.js @@ -275,8 +275,6 @@ const shimmer = (module.exports = { registerCoreInstrumentation(agent) { instrumentProcessMethods(agent) - this._coreInstrumentations = {} - // Instrument each of the core modules. for (const [mojule, core] of Object.entries(CORE_INSTRUMENTATION)) { if (agent.config.instrumentation?.[mojule].enabled === false) { @@ -300,7 +298,7 @@ const shimmer = (module.exports = { resolvedName: mojule }) applyDebugState(shim, core, false) - this._coreInstrumentations[mojule] = _firstPartyInstrumentation(agent, filePath, shim, uninstrumented, mojule) + _firstPartyInstrumentation(agent, filePath, shim, uninstrumented, mojule) } } }, @@ -337,12 +335,6 @@ const shimmer = (module.exports = { if (this._subscribers) { shimmer.teardownSubscribers() } - if (this._coreInstrumentations) { - for (const instrumentation of Object.values(this._coreInstrumentations)) { - instrumentation?.teardown?.() - } - this._coreInstrumentations = {} - } if (this._modulePatch) { this._modulePatch.unpatch() } diff --git a/lib/subscriber-configs.js b/lib/subscriber-configs.js index b52599868f..6ec6304062 100644 --- a/lib/subscriber-configs.js +++ b/lib/subscriber-configs.js @@ -16,6 +16,7 @@ const subscribers = { ...require('./subscribers/bluebird/config'), ...require('./subscribers/bunyan/config'), ...require('./subscribers/cassandra-driver/config'), + ...require('./subscribers/child_process/config'), ...require('./subscribers/connect/config'), ...require('./subscribers/elasticsearch/config'), ...require('./subscribers/express/config'), diff --git a/lib/subscribers/child_process/config.js b/lib/subscribers/child_process/config.js new file mode 100644 index 0000000000..4f3281d183 --- /dev/null +++ b/lib/subscribers/child_process/config.js @@ -0,0 +1,14 @@ +/* + * Copyright 2026 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +// instrumentations are blank because the subscriber is not Orchestrion-based +module.exports = { + child_process: [ + { path: './child_process/exec', instrumentations: [] }, + { path: './child_process/exec-file', instrumentations: [] } + ] +} diff --git a/lib/subscribers/child_process/exec-file.js b/lib/subscribers/child_process/exec-file.js new file mode 100644 index 0000000000..dc0c367438 --- /dev/null +++ b/lib/subscribers/child_process/exec-file.js @@ -0,0 +1,14 @@ +/* + * Copyright 2026 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +const ChildProcessExec = require('./exec') + +module.exports = class ChildProcessExecFile extends ChildProcessExec { + constructor({ agent, logger }) { + super({ agent, logger, methodName: 'execFile' }) + } +} diff --git a/lib/subscribers/child_process/exec.js b/lib/subscribers/child_process/exec.js new file mode 100644 index 0000000000..c787d7978a --- /dev/null +++ b/lib/subscribers/child_process/exec.js @@ -0,0 +1,69 @@ +/* + * Copyright 2026 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +const childProcess = require('child_process') +const TcBaseSubscriber = require('../tc-base') + +module.exports = class ChildProcessExec extends TcBaseSubscriber { + constructor({ agent, logger, methodName = 'exec' }) { + super({ agent, logger, packageName: 'child_process', channelName: methodName }) + this.methodName = methodName + } + + /** + * Patches `childProcess[methodName]` before binding the store -- guarded so + * `setupSubscribers()` constructing/enabling this on every agent cycle + * only ever wraps the method once, ever, per process. + */ + enable() { + this.patch() + super.enable() + } + + patch() { + const methodName = this.methodName + const original = childProcess[methodName] + if (original.__nr_wrapped === true) { + return + } + const channel = this.channel + + childProcess[methodName] = function wrappedMethod(...args) { + const lastArg = args[args.length - 1] + const hasCallback = typeof lastArg === 'function' + const data = { methodName, callbackName: hasCallback ? lastArg.name || '' : null } + + return hasCallback + ? channel.traceCallback(original, -1, data, this, ...args) + : channel.traceSync(original, data, this, ...args) + } + + for (const symbol of Object.getOwnPropertySymbols(original)) { + childProcess[methodName][symbol] = original[symbol] + } + childProcess[methodName].__nr_wrapped = true + } + + handleStart(data, ctx) { + const segment = this.createSegment(ctx, 'child_process.' + data.methodName) + return segment ? ctx.enterSegment({ segment }) : ctx + } + + handleAsyncStart(data, ctx) { + if (!ctx?.segment) { + return ctx + } + ctx.segment.touch() + + const segment = this.createSegment(ctx, 'Callback: ' + data.callbackName) + if (!segment) { + return ctx + } + data.callbackSegment = segment + return ctx.enterSegment({ segment }) + } +} diff --git a/lib/subscribers/tc-base.js b/lib/subscribers/tc-base.js new file mode 100644 index 0000000000..6763728393 --- /dev/null +++ b/lib/subscribers/tc-base.js @@ -0,0 +1,133 @@ +/* + * Copyright 2026 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +// eslint-disable-next-line n/no-unsupported-features/node-builtins +const { tracingChannel } = require('node:diagnostics_channel') + +/** + * Base class for subscribers whose `tracingChannel` is self-created (via + * `tracingChannel(id)`) but published by our own monkeypatch rather than by + * Orchestrion's `ModulePatch` e.g. core Node modules where the target + * method can be patched directly. + * + * Subclasses are responsible for actually publishing to `this.channel` + * (typically from an overridden `enable()`, guarded so the patch only ever + * happens once) and for the `handleStart`/`handleAsyncStart` overrides below. + */ +class TcBaseSubscriber { + constructor({ agent, logger, packageName, channelName }) { + this.agent = agent + this.logger = logger.child({ component: `${packageName}-subscriber` }) + this.config = agent.config + this.packageName = packageName + this.channelName = channelName + this.id = `${packageName}.${channelName}` + this.channel = tracingChannel(this.id) + this.tracer = agent.tracer + this.store = agent.tracer._contextManager._asyncLocalStorage + this._onEnd = this.onEnd.bind(this) + this._onAsyncEnd = this.onAsyncEnd.bind(this) + } + + /** + * Checks if the subscriber is enabled based on the agent's configuration. + * @returns {boolean} if subscriber is enabled + */ + get enabled() { + return this.config.instrumentation[this.packageName].enabled === true + } + + /** + * Creates and starts a segment as a child of the given context's segment. + * @param {Context} ctx active context + * @param {string} name segment name + * @returns {TraceSegment|null} the created segment, or null if none was created + */ + createSegment(ctx, name) { + const segment = this.tracer.createSegment({ name, parent: ctx?.segment, transaction: ctx?.transaction }) + if (segment) { + segment.start() + } + return segment + } + + /** + * Override point: called on `channel.start`. Return the context that + * should become active for the duration of the traced call. + * @param {object} data event data published on `channel.start` + * @param {Context} ctx ambient context at the time `start` fired + * @returns {Context} context to enter + */ + handleStart(data, ctx) { + return ctx + } + + /** + * Override point: called on `channel.asyncStart` (i.e. right before a + * traced callback runs). Return the context that should become active for + * the duration of the callback. + * @param {object} data event data published on `channel.start`/`asyncStart` + * @param {Context} ctx context that was entered on `start` (`data.ctx`) + * @returns {Context} context to enter + */ + handleAsyncStart(data, ctx) { + return ctx + } + + /** + * Default `end` handler -- touches whatever segment `handleStart` entered. + * @param {object} data event data + */ + onEnd(data) { + data.ctx?.segment?.touch() + } + + /** + * Default `asyncEnd` handler -- touches whatever segment + * `handleAsyncStart` created, if any. + * @param {object} data event data + */ + onAsyncEnd(data) { + data.callbackSegment?.touch() + } + + /** + * Binds this subscriber's store to `channel.start`/`asyncStart` so + * `handleStart`/`handleAsyncStart` run scoped to the traced call/callback. + */ + enable() { + this.channel.start.bindStore(this.store, (data) => { + data.ctx = this.handleStart(data, this.tracer.getContext()) + return data.ctx + }) + this.channel.asyncStart.bindStore(this.store, (data) => this.handleAsyncStart(data, data.ctx)) + } + + /** + * Unbinds this subscriber's store from `channel.start`/`asyncStart`. + */ + disable() { + this.channel.start.unbindStore(this.store) + this.channel.asyncStart.unbindStore(this.store) + } + + /** + * Subscribes the default `end`/`asyncEnd` touch handlers. + */ + subscribe() { + this.channel.subscribe({ end: this._onEnd, asyncEnd: this._onAsyncEnd }) + } + + /** + * Unsubscribes the `end`/`asyncEnd` touch handlers. + */ + unsubscribe() { + this.channel.unsubscribe({ end: this._onEnd, asyncEnd: this._onAsyncEnd }) + } +} + +module.exports = TcBaseSubscriber diff --git a/test/unit/instrumentation/core/child_process.test.js b/test/unit/instrumentation/core/child_process.test.js deleted file mode 100644 index a290bdc5ad..0000000000 --- a/test/unit/instrumentation/core/child_process.test.js +++ /dev/null @@ -1,55 +0,0 @@ -/* - * Copyright 2026 New Relic Corporation. All rights reserved. - * SPDX-License-Identifier: Apache-2.0 - */ - -'use strict' - -const test = require('node:test') -const assert = require('node:assert') -const helper = require('#testlib/agent_helper.js') -const childProcessInstrumentation = require('#agentlib/instrumentation/core/child_process.js') - -test('child_process instrumentation', async (t) => { - const agent = helper.loadMockedAgent() - t.after(() => { - helper.unloadAgent(agent) - }) - - await t.test('should log and return false when child_process is not available', () => { - const debugCalls = [] - const stubLogger = { debug: (msg) => debugCalls.push(msg) } - - const result = childProcessInstrumentation(agent, null, { logger: stubLogger }) - - assert.equal(result, false) - assert.deepEqual(debugCalls, ['Could not find child_process, not instrumenting']) - }) - - await t.test('teardown should restore the original exec/execFile', () => { - const originalExec = function exec() {} - const originalExecFile = function execFile() {} - const fakeChildProcess = { exec: originalExec, execFile: originalExecFile } - - const instrumentation = childProcessInstrumentation(agent, fakeChildProcess) - assert.notEqual(fakeChildProcess.exec, originalExec, 'exec should be wrapped after patch') - assert.notEqual(fakeChildProcess.execFile, originalExecFile, 'execFile should be wrapped after patch') - - instrumentation.teardown() - - assert.equal(fakeChildProcess.exec, originalExec, 'exec should be restored after teardown') - assert.equal(fakeChildProcess.execFile, originalExecFile, 'execFile should be restored after teardown') - }) - - await t.test('should not double-wrap after a teardown/re-patch cycle', () => { - const originalExec = function exec() {} - const fakeChildProcess = { exec: originalExec, execFile: function execFile() {} } - - const first = childProcessInstrumentation(agent, fakeChildProcess) - first.teardown() - - const second = childProcessInstrumentation(agent, fakeChildProcess) - - assert.equal(second.originals.exec, originalExec, 'second patch should have wrapped the true original, not a stale wrapper') - }) -}) diff --git a/test/unit/shimmer.test.js b/test/unit/shimmer.test.js index 641d55cb0d..43f62dab06 100644 --- a/test/unit/shimmer.test.js +++ b/test/unit/shimmer.test.js @@ -719,17 +719,6 @@ test('should not throw if you call removeHooks before creating ritm and iitm hoo }) }) -test('should call teardown on core instrumentations that provide it when removeHooks runs', async () => { - const cp = require('child_process') - const originalExec = cp.exec - - const agent = helper.instrumentMockedAgent() - assert.notEqual(cp.exec, originalExec, 'exec should be wrapped after bootstrapping instrumentation') - - helper.unloadAgent(agent) - assert.equal(cp.exec, originalExec, 'exec should be restored to the original after removeHooks tears it down') -}) - test('Shimmer with logger mock', async (t) => { const sandbox = sinon.createSandbox() const loggerMock = require('./mocks/logger')(sandbox) diff --git a/test/unit/subscribers/child_process/exec.test.js b/test/unit/subscribers/child_process/exec.test.js new file mode 100644 index 0000000000..8c8f39234e --- /dev/null +++ b/test/unit/subscribers/child_process/exec.test.js @@ -0,0 +1,34 @@ +/* + * Copyright 2026 New Relic Corporation. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ + +'use strict' + +const test = require('node:test') +const assert = require('node:assert') +const cp = require('child_process') +const helper = require('#testlib/agent_helper.js') +const logger = require('#agentlib/logger.js') +const ChildProcessExec = require('#agentlib/subscribers/child_process/exec.js') + +test('ChildProcessExec subscriber', async (t) => { + const agent = helper.loadMockedAgent() + t.after(() => { + helper.unloadAgent(agent) + }) + + await t.test('should only wrap cp.exec once, even across multiple enable() calls', () => { + const original = cp.exec + + const first = new ChildProcessExec({ agent, logger }) + first.enable() + const wrapped = cp.exec + assert.notEqual(wrapped, original, 'exec should be wrapped after enable()') + + const second = new ChildProcessExec({ agent, logger }) + second.enable() + + assert.equal(cp.exec, wrapped, 'exec should not be wrapped a second time') + }) +}) From c853544afd4550d572250f28c2520fcdcbc06a2a Mon Sep 17 00:00:00 2001 From: Amy Rowen Date: Tue, 11 Aug 2026 09:44:31 -0700 Subject: [PATCH 6/6] Add more tests --- test/integration/core/child-process.test.js | 46 +++++++++++++++++++++ 1 file changed, 46 insertions(+) diff --git a/test/integration/core/child-process.test.js b/test/integration/core/child-process.test.js index 1a2d8b3994..8f9767a277 100644 --- a/test/integration/core/child-process.test.js +++ b/test/integration/core/child-process.test.js @@ -9,6 +9,8 @@ const test = require('node:test') const assert = require('node:assert') const cp = require('child_process') const fs = require('fs') +const path = require('path') +const util = require('util') const helper = require('../../lib/agent_helper') const verifySegments = require('./verify.js') @@ -51,6 +53,50 @@ test('execFile', function (t, end) { }) }) +test('exec via util.promisify', async function (t) { + const { agent } = t.nr + const asyncExec = util.promisify(cp.exec) + + await helper.runInTransaction(agent, async function (tx) { + const { stdout } = await asyncExec('ls', { cwd: __dirname }) + const files = stdout.trim().split('\n').sort() + assert.deepEqual(files, fs.readdirSync(__dirname).sort()) + + const children = tx.trace.getChildren(tx.trace.root.id) + // TODO: should return a 'exec' segment with an internal 'execFile' child + assert.equal(children.length, 1, 'should have exactly one segment, from the internal execFile call') + assert.equal(children[0].name, 'child_process.execFile') + }) +}) + +test('execFile via util.promisify', async function (t) { + const { agent } = t.nr + const asyncExecFile = util.promisify(cp.execFile) + + await helper.runInTransaction(agent, async function (tx) { + const { stdout } = await asyncExecFile(path.join(__dirname, 'exec-me.js')) + assert.equal(stdout, 'I am stdout\n') + + const children = tx.trace.getChildren(tx.trace.root.id) + // TODO: should return a 'execFile' segment + assert.equal(children.length, 0, 'promisified execFile bypasses instrumentation entirely') + }) +}) + +test('exec segment duration should span the full process lifetime', function (t, end) { + const { agent } = t.nr + helper.runInTransaction(agent, function (tx) { + cp.exec('sleep 0.2', function (err) { + assert.ok(!err, 'should not error') + setTimeout(() => { + const [segment] = tx.trace.getChildren(tx.trace.root.id) + assert.ok(segment.getDurationInMillis() >= 150, `segment duration (${segment.getDurationInMillis()}ms) should reflect the sleep, not just the sync call`) + end() + }, 0) + }) + }) +}) + test('transaction context is preserved in subscribed events', function (t, end) { const { agent } = t.nr helper.runInTransaction(agent, function (transaction) {