Description
We have an issue (JIRA NR-353533) wherein a customer is attempting to instrument a long running action. This results in a large amount of system memory being used, and the customer thinking that the agent is causing a memory leak. Memory is not being leaked. The agent operates in a transactional manner, collecting information on all activity during a "request," and only releasing memory when the request has ended. Since the request the customer is instrumenting is effectively a websocket (a "server send event" scenario), the result is a large amount of memory usage.
While investigating this issue, we realized that it could be beneficial if the agent provided a mechanism to disable instrumentation for individual request handlers. We have support for ignoring a transaction, but that doesn't stop the information from being collected in the process. It merely prevents the collected data from being shipped to the New Relic collector.
I took some time to determine if we could provide an API that would solve this problem. I discovered that we could do it, but we would need to review all of our instrumentations to ensure that they all flow through a single hook point. In particular, our core module instrumentations seem to skip the "shim" we utilize for most other instrumentations. Below is a summary of the discovery I performed, and should serve as a jumping off point for solving this issue.
First, I updated shim.record
to recognize decorated entities that should be omitted from instrumentation.
shim.record
node-newrelic/lib/shim/shim.js
Lines 638 to 654 in 7dceae9
My modification (notice the new if
block with the Symbol.for
):
function record(nodule, properties, recordNamer) {
if (this.isFunction(properties)) {
recordNamer = properties
properties = null
}
if (nodule[Symbol.for('newrelic-skip-instrumentation')]) {
return
}
return this.wrap(nodule, properties, function makeWrapper(shim, fn, name) {
// Can't record things that aren't functions.
if (!shim.isFunction(fn)) {
shim.logger.debug('Not recording non-function "%s".', name)
return fn
}
shim.logger.trace('Wrapping "%s" with metric recording.', name)
return recordWrapper({ shim, fn, name, recordNamer })
})
}
Second, I added a new test to verify it works:
bare-router.test.js
test('skips recording transaction if handler is decorated', async t => {
const { agent, app, address, port } = t.nr
const plan = tsplan(t, { plan: 10 })
let finishedCount = 0
agent.on('transactionFinished', tx => {
finishedCount += 1
if (finishedCount !== 2) {
return
}
assertSegments(
tx.trace,
tx.trace.root,
[
'WebTransaction/Expressjs/GET//data',
[
'Expressjs/Route Path: /data',
[
'Nodejs/Middleware/Expressjs/<anonymous>'
]
]
],
{ exact: true },
{ assert: plan }
)
})
app.get('/data', (req, res) => {
res.send('ok')
res.end()
})
handler[Symbol.for('newrelic-skip-instrumentation')] = true
app.get('/test', handler)
const url = `http://localhost:${port}/test`
helper.makeGetRequest(url, { json: true }, (error, res, body) => {
plan.ifError(error)
plan.equal(res.statusCode, 200)
plan.deepEqual(body, { status: 'ok' })
})
await plan.completed
function handler(req, res) {
plan.ok('handler invoked')
http.get(`http://${address}:${port}/data`, response => {
let data = ''
response.on('data', d => { data += d.toString() })
response.on('end', () => {
res.send({ status: data })
res.end()
})
})
}
})
With some modifications to utils.js
:
async function setup(ctx, config = {}) {
ctx.nr = {}
ctx.nr.agent = helper.instrumentMockedAgent(config)
ctx.nr.isExpress5 = isExpress5()
ctx.nr.express = require('express')
ctx.nr.app = ctx.nr.express()
const { promise, resolve } = promiseResolvers()
const server = require('http').createServer(ctx.nr.app)
server.listen(0, TEST_HOST, resolve)
await promise
ctx.nr.server = server
// Added the address to the context:
const address = server.address().address
ctx.nr.address = address.startsWith('::') ? `[${address}]` : address
ctx.nr.port = server.address().port
}
The result are the following traces:
Regular trace that does not ignore anything.
[
0,
2142.9072265625,
"ROOT",
{
"nr_exclusive_duration_millis": 1
},
[
[
0.964417,
2142.394084,
"WebTransaction/Expressjs/GET//test",
{
"request.headers.host": "localhost:52897",
"nr_exclusive_duration_millis": 4.999979499999881
},
[
[
5.480542,
2142.38775,
"Expressjs/Route Path: /test",
{
"code.filepath": "/Users/jsumners/Projects/team-repos/node-newrelic/test/versioned/express/node_modules/router/index.js",
"code.function": "handle",
"code.lineno": 427,
"code.column": 19,
"nr_exclusive_duration_millis": 0.3141904218750824
},
[
[
5.78875,
2142.3817090000002,
"Nodejs/Middleware/Expressjs/handler",
{
"code.filepath": "/Users/jsumners/Projects/team-repos/node-newrelic/test/versioned/express/bare-router.test.js",
"code.function": "handler",
"code.lineno": 109,
"code.column": 19,
"nr_exclusive_duration_millis": 2113.578066421875
},
[
[
2118.810542,
2141.825334,
"External/::1:52897/data",
{
"url": "http://::1:52897/data",
"procedure": "GET",
"nr_exclusive_duration_millis": 17.099997078125
},
[
[
2119.348084,
2125.262917,
"http.Agent#createConnection",
{
"nr_exclusive_duration_millis": 5.34793846875
},
[
[
2120.50725,
2121.0742090000003,
"net.Socket.connect",
{
"nr_exclusive_duration_millis": 0.566959
},
[]
]
]
]
]
]
]
]
]
]
]
]
]
]
Trace that is supposed to ignore the handler
[
0,
691.157958984375,
"ROOT",
{
"nr_exclusive_duration_millis": 1
},
[
[
0.883625,
691.0416660000001,
"WebTransaction/Expressjs/GET//test",
{
"request.headers.host": "localhost:53151",
"nr_exclusive_duration_millis": 4.277669906250026
},
[
[
5.154125,
691.034458,
"Expressjs/Route Path: /test",
{
"code.filepath": "/Users/jsumners/Projects/team-repos/node-newrelic/test/versioned/express/node_modules/router/index.js",
"code.function": "handle",
"code.lineno": 427,
"code.column": 19,
"nr_exclusive_duration_millis": 663.408409171875
},
[
[
668.142166,
690.614125,
"External/::1:53151/data",
{
"url": "http://::1:53151/data",
"procedure": "GET",
"nr_exclusive_duration_millis": 17.709507828125
},
[
[
668.6675829999999,
673.43,
"http.Agent#createConnection",
{
"nr_exclusive_duration_millis": 4.31368653125
},
[
[
669.313208,
669.761916,
"net.Socket.connect",
{
"nr_exclusive_duration_millis": 0.448708
},
[]
]
]
]
]
]
]
]
]
]
]
]
Notice that the Nodejs/Middleware/Expressjs/handler
segment is omitted from the second trace, but the child trace (the outgoing HTTP request) is still included in the second trace. This is not what we want. We want the handler and all child operations to be omitted. But the child operations are being included because the http_outbound
instrumentation does not utilize the shim method we patched.
Metadata
Metadata
Assignees
Type
Projects
Status
Triage Needed: Unprioritized Features