Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Undici prototype #921

Merged
merged 4 commits into from
Sep 28, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 5 additions & 4 deletions lib/feature_flags.js
Original file line number Diff line number Diff line change
Expand Up @@ -7,13 +7,14 @@

// unreleased flags gating an active feature
exports.prerelease = {
express5: false,
await_support: true,
promise_segments: false,
reverse_naming_rules: false,
fastify_instrumentation: false,
certificate_bundle: false,
express5: false,
fastify_instrumentation: false,
new_promise_tracking: false,
promise_segments: false,
reverse_naming_rules: false,
undici_instrumentation: false,
unresolved_promise_cleanup: true
}

Expand Down
2 changes: 1 addition & 1 deletion lib/instrumentation/core/http-outbound.js
Original file line number Diff line number Diff line change
Expand Up @@ -96,7 +96,7 @@ module.exports = function instrumentOutbound(agent, opts, makeRequest) {
} else if (agent.config.cross_application_tracer.enabled) {
cat.addCatHeaders(agent.config, transaction, outboundHeaders)
} else {
logger.trace('CAT disabled, not adding headers!')
logger.trace('Both DT and CAT are disabled, not adding headers!')
}

if (Array.isArray(opts.headers)) {
Expand Down
254 changes: 254 additions & 0 deletions lib/instrumentation/undici.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,254 @@
/*
* Copyright 2021 New Relic Corporation. All rights reserved.
* SPDX-License-Identifier: Apache-2.0
*/

'use strict'

const cat = require('../util/cat')
const recordExternal = require('../metrics/recorders/http_external')
const logger = require('../logger').child({ component: 'undici' })
const NAMES = require('../metrics/names')
const NEWRELIC_SYNTHETICS_HEADER = 'x-newrelic-synthetics'
const SYMBOLS = {
SEGMENT: Symbol('__NR_segment'),
PARENT_SEGMENT: Symbol('__NR_parent_segment')
}

let diagnosticsChannel = null
try {
diagnosticsChannel = require('diagnostics_channel')
} catch (e) {
// quick check to see if module exists
// module was not added until v15.x
}

module.exports = function addUndiciChannels(agent, undici, modName, shim) {
if (!diagnosticsChannel || !agent.config.feature_flag.undici_instrumentation) {
logger.warn(
'diagnostics_channel or feature_flag.undici_instrumentation = false. Skipping undici instrumentation.'
)
return
}

/**
* This event occurs after the Undici Request is created
* We will check current segment for opaque and also attach
* relevant headers to outgoing http request
*
* @param {Object} params
* @param {Object} params.request undici request object
*/
diagnosticsChannel.channel('undici:request:create').subscribe(({ request }) => {
const parent = shim.getSegment()
request[SYMBOLS.PARENT_SEGMENT] = parent
if (!parent || (parent && parent.opaque)) {
logger.trace(
'Not capturing data for outbound request (%s) because parent segment opaque (%s)',
request.path,
parent.name
)

return
}

const transaction = parent.transaction
const outboundHeaders = Object.create(null)
if (agent.config.encoding_key && transaction.syntheticsHeader) {
outboundHeaders[NEWRELIC_SYNTHETICS_HEADER] = transaction.syntheticsHeader
}

if (agent.config.distributed_tracing.enabled) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If aws-sdk ever supported unidici, we'd likely need to build in a check for SHIM_SYMBOLS.DISABLE_DT but I'm guessing there's a lot that would need to be tweaked at that point.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we won't be able to ever support this use case. the headers are already parsed into a string. we can't save a reference to the symbol and get to it ever. Whereas in the http.request instrumentation use case we're parsing before it converts headers from object to string

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't have to use a symbol though.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

true. we could def add a key/value and then strip in here later. i'll file ticket to address this

transaction.insertDistributedTraceHeaders(outboundHeaders)
} else if (agent.config.cross_application_tracer.enabled) {
cat.addCatHeaders(agent.config, transaction, outboundHeaders)
} else {
logger.trace('Both DT and CAT are disabled, not adding headers!')
}

// eslint-disable-next-line guard-for-in
for (const key in outboundHeaders) {
request.addHeader(key, outboundHeaders[key])
}
})

/**
* This event occurs right before the data is written to the socket.
* Undici has some abstracted headers that are only created at this time, one
* is the `host` header which we need to name the Undici segment. So in this
* handler we create, start and set the segment active, name it, and
* attach the url/procedure/request.parameters
*
* @param {Object} params
* @param {Object} params.request undicie request object
* @param {TLSSocket | net.Socket} socket active socket connection
*
*/
diagnosticsChannel.channel('undici:client:sendHeaders').subscribe(({ request, socket }) => {
const parentSegment = request[SYMBOLS.PARENT_SEGMENT]
if (!parentSegment || (parentSegment && parentSegment.opaque)) {
return
}

const port = socket.remotePort
const isHttps = socket.servername
let urlString
if (isHttps) {
urlString = `https://${socket.servername}`
urlString += port === 443 ? request.path : `:${port}${request.path}`
} else {
urlString = `http://${socket._host}`
urlString += port === 80 ? request.path : `:${port}${request.path}`
}

const url = new URL(urlString)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There is some New Relic business logic applied via deeper method calls in urltils.scrubAndParseParameters(request.path). I'm not sure if this particular parsing happens to hit all of those or not. It is obviously nice to use the more desired mechanism at least up front but we may or may not need to apply more logic.

scrub and parseParameters are the functions doing the manual work. Not saying we need to use this but would like to ensure the business logic is consistent.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yea i opted to not use that because with new URL we get all of this for free now. I can file a ticket to update the urlutils to leverage as much built in Node.js functionality as possible

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great. Just wanted to ensure the functionality was equivalent so we didn't accidentally break something.


const name = NAMES.EXTERNAL.PREFIX + url.host + url.pathname
const segment = shim.createSegment(
name,
recordExternal(url.host, 'undici'),
request[SYMBOLS.PARENT_SEGMENT]
)
segment.start()
shim.setActiveSegment(segment)
segment.addAttribute('url', `${url.protocol}//${url.host}${url.pathname}`)

url.searchParams.forEach((value, key) => {
segment.addSpanAttribute(`request.parameters.${key}`, value)
})
segment.addAttribute('procedure', request.method || 'GET')
request[SYMBOLS.SEGMENT] = segment
})

/**
* This event occurs after the response headers have been received.
* We will add the relevant http response attributes to active segment.
* Also add CAT specific keys to active segment.
*
* @param {Object} params
* @param {Object} params.request undici request object
* @param {Object} params.response { statusCode, headers, statusText }
*/
diagnosticsChannel.channel('undici:request:headers').subscribe(({ request, response }) => {
const activeSegment = request[SYMBOLS.SEGMENT]
if (!activeSegment) {
return
}

activeSegment.addSpanAttribute('http.statusCode', response.statusCode)
activeSegment.addSpanAttribute('http.statusText', response.statusText)

if (
agent.config.cross_application_tracer.enabled &&
!agent.config.distributed_tracing.enabled
) {
try {
const { appData } = cat.extractCatHeaders(response.headers)
const decodedAppData = cat.parseAppData(agent.config, appData)
const attrs = activeSegment.getAttributes()
const url = new URL(attrs.url)
cat.assignCatToSegment(decodedAppData, activeSegment, url.host)
} catch (err) {
logger.warn(err, 'Cannot add CAT data to segment')
}
}
})

/**
* This event occurs after the response body has been received.
* We will end the active segment and set the active back to parent before request
* @param {Object} params.request undici request object
*/
diagnosticsChannel.channel('undici:request:trailers').subscribe(({ request }) => {
endAndRestoreSegment(request)
})

/**
* This event occurs right before the request emits an error.
* We will end the active segment and set the active back to parent before request.
* We will also log errors to NR
*
* Note: This event occurs before the error handler so we will always log it for now.
*/
diagnosticsChannel.channel('undici:request:error').subscribe(({ request, error }) => {
endAndRestoreSegment(request, error)
})

/**
* This event occurs before creating connection to socket.
* We will create and start a segment for the `undici.Client.connect`
*
* @param {Object} params
* @param {Function} params.connector function to connect to socket
*/
diagnosticsChannel.channel('undici:client:beforeConnect').subscribe(({ connector }) => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Part of me wonders if we could create the external here as well to capture proper nesting..

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

perhaps. the only thing I see we couldn't get is the host if it is http vs https. i can dig a little

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this won't work. to end the segment we need access to the request object. all the connection hooks just pass along key/values and the connector. I'm going to keep this as is

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sounds good. i do think we'll want something better before going GA, whatever that looks like, but i don't want to derail this PR.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure I understand what better would be. We're subscribing to all the necessary hook points to achieve feature parity with our existing http outbound and http.agent logic. Undici has specifically kept the client and request separate. The client is doing the socket connections(undici:client:beforeConnect, undici:client:connected, and undici:client:connectError) and also adding common headers(undici:client:sendHeaders)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Traditionally, our external calls encompass the time to connect AND the request itself.

In your example above, for example, establishing the connection was the slowest part.

In the unidici trace, the connection was detatched from the external span. While not the end of the world, if you make multiple request to different endpoints it is not obvious which things match to which ones. Which endpoint made you slow and that those are related as far as the call chain is concerned.

Our visual representation to users need-not match the underlying implementation.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ah ok. i wasn't thinking in those terms. I guess for every request you'd get a undici.Client.connect but depending one could be slower than the other. I think we should wait to even log tickets here until we get this in the wild and have users give us feedback though

const parent = shim.getSegment()
const segment = shim.createSegment('undici.Client.connect')
connector[SYMBOLS.SEGMENT] = segment
connector[SYMBOLS.PARENT_SEGMENT] = parent
segment.start()
shim.setActiveSegment(segment)
})

/**
* This event occurs when the socket connection has been made.
* We will end the segment for the `undici.Client.connect` and restores parent
* to before connect
*
* @param {Object} params
* @param {Function} params.connector function to connect to socket
*/
diagnosticsChannel.channel('undici:client:connected').subscribe(({ connector }) => {
endAndRestoreSegment(connector)
})

/**
* This event occurs when connection to socket fails.
* We will end segment for the `undici.Client.connect` and restore parent
* to before connect. It will also attach the error to the transaction
*
* @param {Object} params
* @param {Function} params.connector function to connect to socket
*/
diagnosticsChannel.channel('undici:client:connectError').subscribe(({ connector, error }) => {
endAndRestoreSegment(connector, error)
})

/**
* Gets the active and parent from given ctx(request, client connector)
* and ends active and restores parent to active. If an error exists
* it will add the error to the transaction
*
* @param {Object} ctx request or client connector
* @param {Error} error
*/
function endAndRestoreSegment(ctx, error) {
const activeSegment = ctx[SYMBOLS.SEGMENT]
const parentSegment = ctx[SYMBOLS.PARENT_SEGMENT]
if (activeSegment) {
activeSegment.end()

if (error) {
handleError(activeSegment, error)
}

if (parentSegment) {
shim.setActiveSegment(parentSegment)
}
}
}

/**
* Adds the error to the active transaction
*
* @param {TraceSegment} activeSegment
* @param {Error} error
*/
function handleError(activeSegment, error) {
logger.trace(error, 'Captured outbound error on behalf of the user.')
const tx = activeSegment.transaction
shim.agent.errors.add(tx, error)
}
}

module.exports.SYMBOLS = SYMBOLS
1 change: 1 addition & 0 deletions lib/instrumentations.js
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ module.exports = function instrumentations() {
'redis': { type: MODULE_TYPE.DATASTORE },
'restify': { type: MODULE_TYPE.WEB_FRAMEWORK },
'superagent': { module: '@newrelic/superagent' },
'undici': { type: MODULE_TYPE.TRANSACTION },
'oracle': { type: null },
'vision': { type: MODULE_TYPE.WEB_FRAMEWORK },
'when': { type: null }
Expand Down
3 changes: 2 additions & 1 deletion test/unit/feature_flag.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,8 @@ const used = [
'fastify_instrumentation',
'certificate_bundle',
'new_promise_tracking',
'unresolved_promise_cleanup'
'unresolved_promise_cleanup',
'undici_instrumentation'
]

describe('feature flags', function () {
Expand Down
Loading