Skip to content

Commit

Permalink
Merge pull request #1210 from bizob2828/nr-winston-transport
Browse files Browse the repository at this point in the history
New Relic Log Forwarding Transport
  • Loading branch information
bizob2828 committed May 26, 2022
2 parents 4e7d4f5 + dadae7c commit 0c16aec
Show file tree
Hide file tree
Showing 9 changed files with 521 additions and 284 deletions.
31 changes: 31 additions & 0 deletions THIRD_PARTY_NOTICES.md
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ code, the source code can be found at [https://github.com/newrelic/node-newrelic
* [json-stringify-safe](#json-stringify-safe)
* [readable-stream](#readable-stream)
* [semver](#semver)
* [winston-transport](#winston-transport)

**[devDependencies](#devDependencies)**

Expand Down Expand Up @@ -1330,6 +1331,36 @@ WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR
IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
```

### winston-transport

This product includes source derived from [winston-transport](https://github.com/winstonjs/winston-transport) ([v4.5.0](https://github.com/winstonjs/winston-transport/tree/v4.5.0)), distributed under the [MIT License](https://github.com/winstonjs/winston-transport/blob/v4.5.0/LICENSE):

```
The MIT License (MIT)
Copyright (c) 2015 Charlie Robbins & the contributors.
Permission is hereby granted, free of charge, to any person obtaining a copy
of this software and associated documentation files (the "Software"), to deal
in the Software without restriction, including without limitation the rights
to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
copies of the Software, and to permit persons to whom the Software is
furnished to do so, subject to the following conditions:
The above copyright notice and this permission notice shall be included in all
copies or substantial portions of the Software.
THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
SOFTWARE.
```


Expand Down
108 changes: 108 additions & 0 deletions lib/instrumentation/nr-winston-transport.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,108 @@
/*
* Copyright 2022 New Relic Corporation. All rights reserved.
* SPDX-License-Identifier: Apache-2.0
*/

'use strict'
const TransportStream = require('winston-transport')
const logger = require('../logger').child({ component: 'nr-winston-transport' })
const { truncate } = require('../util/application-logging')

/**
* Transport used to prepare a log line and add to the new relic agent
* log aggregator.
*
* Note*: This copies the log line so no other transports will get the
* mutated data.
*/
class NrTransport extends TransportStream {
constructor(opts = {}) {
// set this option to have winston handle uncaught exceptions
// See: https://github.com/winstonjs/winston#handling-uncaught-exceptions-with-winston
opts.handleExceptions = true
super(opts)
this.name = 'newrelic'
this.agent = opts.agent
this.config = opts.agent.config
}

/**
* Executed on every log line. We will get the linking metadata
* and add this, along with reformatting of timestamp and error
* to a copy of the log line
*
* @param {object} logLine a winston log line
* @param {Function} callback callback to invoke once we are done
*/
log(logLine, callback) {
const metadata = this.agent.getLinkingMetadata()
const formattedLine = reformatLogLine(logLine, metadata, this.agent)
this.agent.logs.add(formattedLine)
callback()
}
}

module.exports = NrTransport

/**
* Reformats a log line by reformatting errors, timestamp and adding
* new relic linking metadata(context). When uncaught exceptions exist
* an exception property will exist on the log line. This will tell us
* that we need to reformat the error
*
* @param {object} logLine log line
* @param {object} metadata linking metadata
* @param {object} agent NR agent
* @returns {object} copy of log line with NR linking metadata
*/
function reformatLogLine(logLine, metadata, agent) {
// Add the metadata to a copy of the logLine
const formattedLine = Object.assign({}, logLine, metadata)

if (formattedLine.exception === true) {
reformatError(formattedLine)
}

reformatTimestamp(formattedLine, agent)

return formattedLine
}

/**
* Decorates the log line with truncated error.message, error.class, and error.stack and removes
* trace and stack
*
* @param {object} logLine a log line
*/
function reformatError(logLine) {
// Due to Winston internals sometimes the error on the logLine object is a string or an
// empty object, and so the message property is all we have
const errorMessage = logLine.error.message || logLine.message || ''

logLine['error.message'] = truncate(errorMessage)
logLine['error.class'] =
logLine.error.name === 'Error' ? logLine.error.constructor.name : logLine.error.name
logLine['error.stack'] = truncate(logLine.error.stack)
logLine.message = truncate(logLine.message)

// Removes additional capture of stack to reduce overall payload/log-line size.
// The server has a maximum of ~4k characters per line allowed.
delete logLine.trace
delete logLine.stack
}

/**
* Turns timestamp into unix timestamp. If timestamp existed it will move original
* to `original_timestamp` key
*
* @param {object} logLine a log line
*/
function reformatTimestamp(logLine) {
if (logLine.timestamp) {
logger.traceOnce(
'Overwriting `timestamp` key; assigning original value to `original_timestamp`.'
)
logLine.original_timestamp = logLine.timestamp
}
logLine.timestamp = Date.now()
}
118 changes: 23 additions & 95 deletions lib/instrumentation/winston.js
Original file line number Diff line number Diff line change
Expand Up @@ -12,10 +12,11 @@ const {
isLocalDecoratingEnabled,
isMetricsEnabled,
createModuleUsageMetric,
incrementLoggingLinesMetrics,
truncate
incrementLoggingLinesMetrics
} = require('../util/application-logging')

const logger = require('../logger').child({ component: 'winston' })
const NrTransport = require('./nr-winston-transport')

module.exports = function instrument(agent, winston, _, shim) {
const config = agent.config
Expand All @@ -33,145 +34,72 @@ module.exports = function instrument(agent, winston, _, shim) {
return createLogger.apply(this, args)
}

registerFormatter({ opts, config, agent, winston })
createModuleUsageMetric('winston', agent.metrics)

if (isLocalDecoratingEnabled(config) || isMetricsEnabled(config)) {
registerFormatter({ opts, agent, winston })
}

const winstonLogger = createLogger.apply(this, args)

return createLogger.apply(this, args)
if (isLogForwardingEnabled(config, agent)) {
winstonLogger.add(new NrTransport({ agent }))
}

return winstonLogger
}
})
}

/**
* There is no right way to do this. But since we are automagical
* it is hard to predict how a customer uses winston. We will iterate over the formatters specified on the logger and add last if forwarder or first if local decorating.
* This is because we want all the customizations of previous formatters before adding log log to log aggregator. But in the case of local decorating we want to do this first so any formatter that is transforming data will have the changes.
*
* Note: The logic explained above does not apply if a customer specifies multiple formats for a given transport.
* We cannot instrument the formats on the transport because if a customer has multiple transports we would be duplicating logs when forwaring.
* Apply a formatter to keep track of logging metrics, and in the case of local decorating appending
* the NR-LINKING metadata to message. We want to do this first so any formatter that is transforming
* data will have the changes.
*
* @param {object} params object passed to function
* @param {object} params.opts options from winston.createLogger
* @param {object} params.config agent config
* @param {object} params.agent NR agent
* @param {object} params.winston exported winston package
*/
function registerFormatter({ opts, config, agent, winston }) {
function registerFormatter({ opts, agent, winston }) {
const instrumentedFormatter = nrWinstonFormatter(agent, winston)

if ('format' in opts) {
const formatters = [opts.format]

if (isLogForwardingEnabled(config, agent)) {
formatters.push(instrumentedFormatter())
} else {
formatters.unshift(instrumentedFormatter())
}

opts.format = winston.format.combine(...formatters)
opts.format = winston.format.combine(instrumentedFormatter(), opts.format)
} else {
opts.format = instrumentedFormatter()
}
}

/**
* This formatter is being used to facilitate
* the application logging use cases.
* It is worth noting that the features below are mutually
* exclusive.
*
* The application logging use cases are local log decorating
* and log forwarding.
* the two application logging use cases: metrics and local log decorating.
*
* Local log decorating appends `NR-LINKING` piped metadata to
* the message key in log line. You must configure a log forwarder to get
* this data to NR1.
*
* Log forwarding includes the linking metadata as keys on logging
* object as well as adds the log line to the agent log aggregator.
*
* @param {object} agent NR agent
* @param {object} winston exported winston package
* @returns {object} log line with NR context or NR-LINKING metadata on message
* @returns {object} log line NR-LINKING metadata on message when local log decorating is enabled
*/
function nrWinstonFormatter(agent, winston) {
const config = agent.config
const metrics = agent.metrics
createModuleUsageMetric('winston', metrics)

return winston.format((logLine) => {
if (isMetricsEnabled(config)) {
incrementLoggingLinesMetrics(logLine.level, metrics)
}

if (isLogForwardingEnabled(config, agent)) {
const metadata = agent.getLinkingMetadata()
reformatLogLine(logLine, metadata, agent)
agent.logs.add(logLine)
} else if (isLocalDecoratingEnabled(config)) {
if (isLocalDecoratingEnabled(config)) {
logLine.message += agent.getNRLinkingMetadata()
}

return logLine
})
}

/**
* Reformats a log line by reformatting errors, timestamp and adding
* new relic linking metadata(context)
*
* @param {object} logLine log line
* @param {object} metadata linking metadata
* @param {object} agent NR agent
*/
function reformatLogLine(logLine, metadata, agent) {
if (logLine.exception === true) {
reformatError(logLine)
}

reformatTimestamp(logLine, agent)

// Add the metadata to the logLine object being logged
Object.assign(logLine, metadata)
}

/**
* Decorates the log line with truncated error.message, error.class, and error.stack and removes
* trace and stack
*
* @param {object} logLine a log line
*/
function reformatError(logLine) {
// Due to Winston internals sometimes the error on the logLine object is a string or an
// empty object, and so the message property is all we have
const errorMessage = logLine.error.message || logLine.message || ''

logLine['error.message'] = truncate(errorMessage)
logLine['error.class'] =
logLine.error.name === 'Error' ? logLine.error.constructor.name : logLine.error.name
logLine['error.stack'] = truncate(logLine.error.stack)
logLine.message = truncate(logLine.message)

// Removes additional capture of stack to reduce overall payload/log-line size.
// The server has a maximum of ~4k characters per line allowed.
delete logLine.trace
delete logLine.stack
}

/**
* Turns timestamp into unix timestamp. If timestamp existed it will move original
* to `original_timestamp` key
*
* @param {object} logLine a log line
*/
function reformatTimestamp(logLine) {
if (logLine.timestamp) {
logger.traceOnce(
'Overwriting `timestamp` key; assigning original value to `original_timestamp`.'
)
logLine.original_timestamp = logLine.timestamp
}
logLine.timestamp = Date.now()
}

/**
* winston allows you to compose a logger
* from an instantiated logger. Through a series
Expand Down
Loading

0 comments on commit 0c16aec

Please sign in to comment.