From cf67cb815aeced3d4355f2467158042eada21880 Mon Sep 17 00:00:00 2001 From: Clinton Blackburn Date: Sun, 11 Jul 2021 21:48:36 -0700 Subject: [PATCH] Duplicating message objects to avoid modifying input Objects passed to the log() or level-specific methods are cloned to ensure the original object is not modified. This ensures the input objects do not end up with additional fields (e.g., level), and existing fields, such as data or metadata, are not modified by default metadata or formatters. --- lib/winston/create-logger.js | 4 ++- lib/winston/logger.js | 3 +++ test/logger.test.js | 51 +++++++++++++++++++++++++----------- 3 files changed, 42 insertions(+), 16 deletions(-) diff --git a/lib/winston/create-logger.js b/lib/winston/create-logger.js index e868aeaad..91502cb43 100644 --- a/lib/winston/create-logger.js +++ b/lib/winston/create-logger.js @@ -75,7 +75,9 @@ module.exports = function (opts = {}) { // Optimize the hot-path which is the single object. if (args.length === 1) { const [msg] = args; - const info = msg && msg.message && msg || { message: msg }; + // NOTE: If `msg` is an Object, clone it so changes made, such as the addition of the level field, + // do not affect the original object. + const info = msg && msg.message && { ...msg } || { message: msg }; info.level = info[LEVEL] = level; self._addDefaultMeta(info); self.write(info); diff --git a/lib/winston/logger.js b/lib/winston/logger.js index dc7866854..b11280e88 100644 --- a/lib/winston/logger.js +++ b/lib/winston/logger.js @@ -214,6 +214,9 @@ class Logger extends Transform { // Slightly less hotpath, but worth optimizing for. if (arguments.length === 2) { if (msg && typeof msg === 'object') { + // NOTE: If `msg` is an Object, clone it so changes made, such as the addition of the level field, + // do not affect the original object. + msg = { ...msg }; msg[LEVEL] = msg.level = level; this._addDefaultMeta(msg); this.write(msg); diff --git a/test/logger.test.js b/test/logger.test.js index 0d21d3fa1..223a3b960 100755 --- a/test/logger.test.js +++ b/test/logger.test.js @@ -64,7 +64,7 @@ describe('Logger', function () { Object.keys(winston.config.syslog.levels).forEach(level => { assume(logger[level]).is.a('function'); - }) + }); }); it('new Logger({ levels }) custom methods are not bound to instance', function (done) { @@ -74,16 +74,16 @@ describe('Logger', function () { transports: [] }); - let logs = []; - let extendedLogger = Object.create(logger, { + const logs = []; + const extendedLogger = Object.create(logger, { write: { - value: function(...args) { + value: function (...args) { logs.push(args); if (logs.length === 4) { assume(logs.length).is.eql(4); assume(logs[0]).is.eql([{ test: 1, level: 'info' }]); assume(logs[1]).is.eql([{ test: 2, level: 'warn' }]); - assume(logs[2]).is.eql([{ message: 'test3', level: 'info' }]) + assume(logs[2]).is.eql([{ message: 'test3', level: 'info' }]); assume(logs[3]).is.eql([{ with: 'meta', test: 4, level: 'warn', @@ -160,7 +160,7 @@ describe('Logger', function () { it('.configure({ transports, format })', function () { var logger = winston.createLogger(), - format = logger.format; + format = logger.format; assume(logger.transports.length).equals(0); @@ -177,7 +177,7 @@ describe('Logger', function () { it('.remove() [transport not added]', function () { var transports = [ new winston.transports.Console(), - new winston.transports.File({ filename: path.join(__dirname, 'fixtures', 'logs', 'filelog.log' )}) + new winston.transports.File({ filename: path.join(__dirname, 'fixtures', 'logs', 'filelog.log') }) ]; var logger = winston.createLogger({ transports: transports }) @@ -193,7 +193,7 @@ describe('Logger', function () { it('.remove() [TransportStream]', function () { var transports = [ new winston.transports.Console(), - new winston.transports.File({ filename: path.join(__dirname, 'fixtures', 'logs', 'filelog.log' )}) + new winston.transports.File({ filename: path.join(__dirname, 'fixtures', 'logs', 'filelog.log') }) ]; var logger = winston.createLogger({ transports: transports }); @@ -211,7 +211,7 @@ describe('Logger', function () { assume(logger.transports.length).equals(0); }); - it ('.clear() [transports]', function () { + it('.clear() [transports]', function () { var logger = winston.createLogger({ transports: [new winston.transports.Console()] }); @@ -343,9 +343,9 @@ describe('Logger (levels)', function () { it('custom levels', function (done) { var logger = winston.createLogger({ levels: { - bad: 0, + bad: 0, test: 1, - ok: 2 + ok: 2 } }); @@ -628,7 +628,7 @@ describe('Logger (stream semantics)', function () { it(`rethrows errors from user-defined formats`, function () { stdMocks.use(); - const logger = winston.createLogger( { + const logger = winston.createLogger({ transports: [new winston.transports.Console()], format: winston.format.printf((info) => { // Set a trap. @@ -672,7 +672,7 @@ describe('Logger (winston@2 logging API)', function () { done(); }); - logger.log('info', 'Some super awesome log message') + logger.log('info', 'Some super awesome log message'); }); it(`.log(level, undefined) creates info with { message: undefined }`, function (done) { @@ -810,6 +810,27 @@ describe('Logger (logging exotic data types)', function () { logger.info('Hello', { label: 'world' }); logger.info('Hello %d', 100, { label: 'world' }); }); + + it('does not modify objects passed as messages', () => { + const logger = winston.createLogger(); + const msg = { + name: 'BadRequest', + message: 'This is a test', + code: 400, + className: 'bad-request', + data: { + foo: 'bar' + }, + errors: {} + }; + const originalMsg = { ...msg }; + logger.info(msg); + assume(msg).deep.equals(originalMsg); + + // NOTE: We test both info() and log() because they are two separate code paths. + logger.log('info', msg); + assume(msg).deep.equals(originalMsg); + }); }); describe('.info', function () { @@ -871,7 +892,7 @@ describe('Logger (profile, startTimer)', function (done) { logger.profile('testing1', { something: 'ok', level: 'info' - }) + }); }, 100); }); @@ -894,7 +915,7 @@ describe('Logger (profile, startTimer)', function (done) { logger.profile('testing2', { something: 'ok', level: 'info' - }) + }); }, 100); });