Skip to content

Commit

Permalink
fix: Fixed handling of Pino merging object (#2600)
Browse files Browse the repository at this point in the history
  • Loading branch information
jsumners-nr authored Sep 23, 2024
1 parent 92e6978 commit de3c266
Show file tree
Hide file tree
Showing 3 changed files with 84 additions and 1 deletion.
10 changes: 9 additions & 1 deletion lib/instrumentation/pino/pino.js
Original file line number Diff line number Diff line change
Expand Up @@ -131,7 +131,15 @@ function reformatLogLine({ logLine, msg, agent, chindings = '', level, logger })
delete metadata.hostname
}

const agentMeta = Object.assign({}, { timestamp: Date.now(), message: msg }, metadata)
const agentMeta = Object.assign({}, { timestamp: Date.now() }, metadata)
// eslint-disable-next-line eqeqeq
if (msg != undefined) {
// The spec lists `message` as "MUST" under the required column, but then
// details that it "MUST be omitted" if the value is "empty". Additionally,
// if someone has logged only a merging object, and that object contains a
// message key, we do not want to overwrite their value. See issue 2595.
agentMeta.message = msg
}

/**
* A function that gets executed in `_toPayloadSync` of log aggregator.
Expand Down
62 changes: 62 additions & 0 deletions test/versioned/pino/issue-2595.test.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,62 @@
/*
* Copyright 2024 New Relic Corporation. All rights reserved.
* SPDX-License-Identifier: Apache-2.0
*/

'use strict'

const test = require('node:test')
const assert = require('node:assert')
const { Writable } = require('node:stream')

const helper = require('../../lib/agent_helper')

test('does not strip message property', (t, end) => {
const logs = []
const dest = new Writable({
write(chunk, encoding, callback) {
logs.push(JSON.parse(chunk.toString()))
callback()
}
})
const agent = helper.instrumentMockedAgent({
application_logging: {
forwarding: { enabled: true }
}
})
const pinoHttp = require('pino-http')
const { logger } = pinoHttp({ level: 'info' }, dest)

helper.runInTransaction(agent, (tx) => {
logger.info({ message: 'keep me', message2: 'me too' })

tx.end()

const agentLogs = agent.logs.getEvents()
assert.equal(agentLogs.length, 1, 'aggregator should have recorded log')
assert.equal(logs.length, 1, 'stream should have recorded one log')

// Verify the destination stream log has the expected properties.
const expectedLog = logs[0]
assert.equal(expectedLog.message, 'keep me')
assert.equal(expectedLog.message2, 'me too')

const foundLog = agentLogs[0]()

// The forwarded log should have all of the extra keys that were logged to
// the destination stream by Pino.
const expectedKeys = Object.keys(expectedLog).filter(
(k) => ['level', 'time', 'pid', 'hostname'].includes(k) === false // Omit baseline Pino keys.
)
for (const key of expectedKeys) {
assert.equal(Object.hasOwn(foundLog, key), true, `forwarded log should have key "${key}"`)
assert.equal(
foundLog[key],
expectedLog[key],
`"${key}" key should have same value as original log`
)
}

end()
})
})
13 changes: 13 additions & 0 deletions test/versioned/pino/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,19 @@
"files": [
"pino.tap.js"
]
},

{
"engines": {
"node": ">=18"
},
"dependencies": {
"pino": ">=7.0.0",
"pino-http": ">=10.3.0"
},
"files": [
"issue-2595.test.js"
]
}
]
}

0 comments on commit de3c266

Please sign in to comment.