Skip to content

Commit

Permalink
fix: Pick log message from merging object in Pino instrumentation
Browse files Browse the repository at this point in the history
  • Loading branch information
jsumners-nr committed Aug 1, 2024
1 parent 0dfab8c commit c6c3ac9
Show file tree
Hide file tree
Showing 2 changed files with 41 additions and 3 deletions.
13 changes: 11 additions & 2 deletions lib/instrumentation/pino/pino.js
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ const {
} = require('../../util/application-logging')
const semver = require('semver')

// eslint-disable-next-line sonarjs/cognitive-complexity
module.exports = function instrument(shim, tools) {
const pinoVersion = shim.pkgVersion

Expand Down Expand Up @@ -50,13 +51,21 @@ module.exports = function instrument(shim, tools) {
return function wrappedAsJson() {
const args = shim.argsToArray.apply(shim, arguments)
const level = this?.levels?.labels?.[args[2]]
// Pino log methods accept a singular object (a merging object) that can
// have a `msg` property for the log message. In such cases, we need to
// update that log property instead of the second parameter.
const useMergeObj = args[1] === undefined && Object.hasOwn(args[0], 'msg')

if (isMetricsEnabled(config)) {
incrementLoggingLinesMetrics(level, metrics)
}

if (isLocalDecoratingEnabled(config)) {
args[1] += agent.getNRLinkingMetadata()
if (useMergeObj === true) {
args[0].msg += agent.getNRLinkingMetadata()
} else {
args[1] += agent.getNRLinkingMetadata()
}
}

/**
Expand All @@ -69,7 +78,7 @@ module.exports = function instrument(shim, tools) {
if (isLogForwardingEnabled(config, agent)) {
const chindings = this[symbols.chindingsSym]
const formatLogLine = reformatLogLine({
msg: args[1],
msg: useMergeObj === true ? args[0].msg : args[1],
logLine,
agent,
chindings,
Expand Down
31 changes: 30 additions & 1 deletion test/versioned/pino/pino.tap.js
Original file line number Diff line number Diff line change
Expand Up @@ -83,14 +83,28 @@ tap.test('Pino instrumentation', (t) => {
const message = 'pino decorating test'
helper.runInTransaction(agent, 'pino-test', async () => {
logger.info(message)
const line = await once(stream, 'data')
let line = await once(stream, 'data')
originalMsgAssertion({
t,
includeLocalDecorating: true,
hostname: agent.config.getHostnameSafe(),
logLine: line
})
t.same(agent.logs.getEvents(), [], 'should not add any logs to log aggregator')

// Verify that merging object only logs get decorated:
logger.info({ msg: message })
line = await once(stream, 'data')
console.log(line)
t.equal(line.msg.startsWith(`${message} NR-LINKING|test-guid`), true)
originalMsgAssertion({
t,
includeLocalDecorating: true,
hostname: agent.config.getHostnameSafe(),
logLine: line
})
t.same(agent.logs.getEvents(), [], 'should not add any logs to log aggregator')

t.end()
})
})
Expand Down Expand Up @@ -375,4 +389,19 @@ tap.test('Pino instrumentation', (t) => {
})
})
})

t.test('should honor msg key in merging object (issue 2410)', async (t) => {
t.context.config = setupAgent(t.context, { application_logging: { enabled: true } })
const { agent, config, pino } = t.context
const localStream = sink()
const localLogger = pino({ base: undefined }, localStream)
const message = 'pino unit test'
const level = 'info'
localLogger[level]({ msg: message })
await once(localStream, 'data')
t.equal(agent.logs.getEvents().length, 1, 'should have 1 log in aggregator')
const formattedLine = agent.logs.getEvents()[0]()
t.validateAnnotations({ line: formattedLine, message, level, config })
t.end()
})
})

0 comments on commit c6c3ac9

Please sign in to comment.