diff --git a/lib/instrumentation/pino/pino.js b/lib/instrumentation/pino/pino.js index fd5b1e9931..0db720c2e0 100644 --- a/lib/instrumentation/pino/pino.js +++ b/lib/instrumentation/pino/pino.js @@ -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. diff --git a/test/versioned/pino/issue-2595.test.js b/test/versioned/pino/issue-2595.test.js new file mode 100644 index 0000000000..606077924c --- /dev/null +++ b/test/versioned/pino/issue-2595.test.js @@ -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() + }) +}) diff --git a/test/versioned/pino/package.json b/test/versioned/pino/package.json index 1abccb91a7..63e29b1918 100644 --- a/test/versioned/pino/package.json +++ b/test/versioned/pino/package.json @@ -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" + ] } ] }