Skip to content

Commit

Permalink
fix: Updated winston instrumentation to wrap configure to properly re…
Browse files Browse the repository at this point in the history
…tain our transporter to do log forwarding (#1987)
  • Loading branch information
bizob2828 authored Jan 31, 2024
1 parent 5eae6ee commit b54a97f
Show file tree
Hide file tree
Showing 2 changed files with 131 additions and 2 deletions.
48 changes: 46 additions & 2 deletions lib/instrumentation/winston.js
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,8 @@ module.exports = function instrument(agent, winston, _, shim) {
shim.wrap(winston, 'createLogger', function wrapCreate(shim, createLogger) {
return function wrappedCreateLogger() {
const args = shim.argsToArray.apply(shim, arguments)
const opts = args[0] || {}
// re-assign the first arg to an object if does not exist so we can assign the default formatter
const opts = (args[0] = args[0] || {})
if (isStream(opts)) {
return createLogger.apply(this, args)
}
Expand All @@ -39,6 +40,7 @@ module.exports = function instrument(agent, winston, _, shim) {
opts,
agent,
winston,
shim,
registerLogger: createLogger
})
}
Expand All @@ -61,13 +63,29 @@ module.exports = function instrument(agent, winston, _, shim) {
opts,
agent,
winston,
shim,
registerLogger: add
})
}
})
}

function performInstrumentation({ obj, args, opts, agent, winston, registerLogger }) {
/**
* Does the necessary instrumentation depending on application_logging configuration.
* It will register a formatter to track metrics or decorate message in formatter(if local log decoration)
* and register a transport do to the log fowarding
*
* @param {object} params object passed to function
* @param {object} params.obj instance of winston logger
* @param {Array} params.args arguments passed to the logger creation method(createLogger or logger.add)
* @param {object} params.opts the logger options argument
* @param {Agent} params.agent NR instance
* @param {object} params.winston the winston export
* @param {Shim} params.shim shim instance
* @param {Function} params.registerLogger the function to create winston logger
* @returns {object} the winston logger instance with relevant instrumentation
*/
function performInstrumentation({ obj, args, opts, agent, winston, shim, registerLogger }) {
const config = agent.config

createModuleUsageMetric('winston', agent.metrics)
Expand All @@ -80,11 +98,37 @@ function performInstrumentation({ obj, args, opts, agent, winston, registerLogge

if (isLogForwardingEnabled(config, agent)) {
winstonLogger.add(new NrTransport({ agent }))
wrapConfigure({ shim, winstonLogger, agent })
}

return winstonLogger
}

/**
* Wraps logger.configure and checks the transports key in the arguments and adds the NrTransport as
* it will get cleared in configure.
*
* @param {object} params object passed to function
* @param {object} params.shim shim instance
* @param {object} params.winstonLogger instance of logger
* @param {object} params.agent NR agent
*/
function wrapConfigure({ shim, winstonLogger, agent }) {
shim.wrap(winstonLogger, 'configure', function nrConfigure(shim, configure) {
return function wrappedConfigure() {
const args = shim.argsToArray.apply(shim, arguments)
const transportsArg = args?.[0]?.transports
if (this.transports.length) {
const nrTransport = new NrTransport({ agent })
args[0].transports = Array.isArray(transportsArg)
? [...transportsArg, nrTransport]
: nrTransport
}
return configure.apply(this, args)
}
})
}

/**
* 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
Expand Down
85 changes: 85 additions & 0 deletions test/versioned/winston/winston.tap.js
Original file line number Diff line number Diff line change
Expand Up @@ -267,6 +267,34 @@ tap.test('winston instrumentation', (t) => {
logWithAggregator({ logger, stream: jsonStream, t, helper, agent })
})

t.test('should add linking metadata when using logger.configure', (t) => {
const handleMessages = makeStreamTest(() => {
const msgs = agent.logs.getEvents()
t.equal(msgs.length, 2, 'should add both logs to aggregator')
msgs.forEach((msg) => {
logForwardingMsgAssertion(t, msg, agent)
t.ok(msg.original_timestamp, 'should put customer timestamp on original_timestamp')
})
t.end()
})
const assertFn = originalMsgAssertion.bind(null, { t, timestamp: true })
const jsonStream = concat(handleMessages(assertFn))
// Example Winston setup to test
const logger = winston.createLogger()
logger.configure({
format: winston.format.timestamp('YYYY-MM-DD HH:mm:ss'),
transports: [
// Log to a stream so we can test the output
new winston.transports.Stream({
level: 'info',
stream: jsonStream
})
]
})

logWithAggregator({ logger, stream: jsonStream, t, helper, agent })
})

t.test('should properly reformat errors on msgs to log aggregator', (t) => {
const name = 'TestError'
const errorMsg = 'throw uncaught exception test'
Expand Down Expand Up @@ -519,6 +547,63 @@ tap.test('winston instrumentation', (t) => {
})
}

t.test(`should count logger metrics for logger.configure`, (t) => {
setup({
application_logging: {
enabled: true,
metrics: {
enabled: true
},
forwarding: { enabled: false },
local_decorating: { enabled: false }
}
})

const logger = winston.createLogger()
logger.configure({
transports: [
new winston.transports.Stream({
level: 'debug',
// We don't care about the output for this test, just
// total lines logged
stream: nullStream
})
]
})

helper.runInTransaction(agent, 'winston-test', () => {
const logLevels = {
debug: 20,
info: 5,
warn: 3,
error: 2
}
for (const [logLevel, maxCount] of Object.entries(logLevels)) {
for (let count = 0; count < maxCount; count++) {
const msg = `This is log message #${count} at ${logLevel} level`
logger[logLevel](msg)
}
}

// Close the stream so that the logging calls are complete
nullStream.end()

let grandTotal = 0
for (const [logLevel, maxCount] of Object.entries(logLevels)) {
grandTotal += maxCount
const metricName = LOGGING.LEVELS[logLevel.toUpperCase()]
const metric = agent.metrics.getMetric(metricName)
t.ok(metric, `ensure ${metricName} exists`)
t.equal(metric.callCount, maxCount, `ensure ${metricName} has the right value`)
}
const metricName = LOGGING.LINES
const metric = agent.metrics.getMetric(metricName)
t.ok(metric, `ensure ${metricName} exists`)
t.equal(metric.callCount, grandTotal, `ensure ${metricName} has the right value`)
t.end()
})
})

const configValues = [
{
name: 'application_logging is not enabled',
Expand Down

0 comments on commit b54a97f

Please sign in to comment.