Clone incoming objects to prevent incoming data mutation (Issue #1775)

lib/winston/common.js

@@ -44,3 +44,30 @@ exports.warn = {
     });
   }
 };
+
+
+exports.dataUtils = {
+  /**
+   * Creates a deep copy of an object
+   * @param {Object | string} data The data to clone
+   * @returns {Object} A deep copy of the parameter object
+   */
+  cloneObject(data) {
+    const isError = Object.prototype.toString.call(data) === '[object Error]';
+    const isObject = typeof data === 'object';
+
+    if (isError) {
+      let nextErr = new Error(data.message);
+
+      nextErr.stack = data.stack;
+      Object.assign(nextErr, data);
+
+      return nextErr;
+    } else if (isObject) {
+      return Object.assign({}, data);
+    }
+
+    // Assume the primitive case
+    return data;
+  }
+};

lib/winston/create-logger.js

@@ -10,6 +10,7 @@
 const { LEVEL } = require('triple-beam');
 const config = require('./config');
 const Logger = require('./logger');
+const { dataUtils } = require('./common');
 const debug = require('@dabh/diagnostics')('winston:create-logger');
 
 function isLevelEnabledFunctionName(level) {
@@ -75,7 +76,7 @@ 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 };
+        const info = msg && msg.message && dataUtils.cloneObject(msg) || { message: msg };
         info.level = info[LEVEL] = level;
         self._addDefaultMeta(info);
         self.write(info);

lib/winston/logger.js

@@ -15,7 +15,7 @@ const ExceptionHandler = require('./exception-handler');
 const RejectionHandler = require('./rejection-handler');
 const LegacyTransportStream = require('winston-transport/legacy');
 const Profiler = require('./profiler');
-const { warn } = require('./common');
+const { warn, dataUtils } = require('./common');
 const config = require('./config');
 
 /**
@@ -205,30 +205,33 @@ class Logger extends Transform {
    */
   /* eslint-enable valid-jsdoc */
   log(level, msg, ...splat) {
+    let msgCopy;
     // eslint-disable-line max-params
     // Optimize for the hotpath of logging JSON literals
     if (arguments.length === 1) {
       // Yo dawg, I heard you like levels ... seriously ...
       // In this context the LHS `level` here is actually the `info` so read
       // this as: info[LEVEL] = info.level;
-      level[LEVEL] = level.level;
-      this._addDefaultMeta(level);
-      this.write(level);
+      msgCopy = dataUtils.cloneObject(level);
+      msgCopy[LEVEL] = level.level;
+      this._addDefaultMeta(msgCopy);
+      this.write(msgCopy);
       return this;
     }
 
     // Slightly less hotpath, but worth optimizing for.
     if (arguments.length === 2) {
       if (msg && typeof msg === 'object') {
-        msg[LEVEL] = msg.level = level;
-        this._addDefaultMeta(msg);
-        this.write(msg);
+        msgCopy = dataUtils.cloneObject(msg);
+        msgCopy[LEVEL] = msgCopy.level = level;
+        this._addDefaultMeta(msgCopy);
+        this.write(msgCopy);
         return this;
       }
 
-      msg = { [LEVEL]: level, level, message: msg };
-      this._addDefaultMeta(msg);
-      this.write(msg);
+      msgCopy = { [LEVEL]: level, level, message: msg };
+      this._addDefaultMeta(msgCopy);
+      this.write(msgCopy);
       return this;
     }
 
@@ -243,7 +246,7 @@ class Logger extends Transform {
           [LEVEL]: level,
           [SPLAT]: splat,
           level,
-          message: msg
+          message: dataUtils.cloneObject(msg)
         });
 
         if (meta.message) info.message = `${info.message} ${meta.message}`;

test/unit/formats/errors.test.js

@@ -35,14 +35,19 @@ function assumeExpectedInfo(info, target = {}) {
   });
 }
 
+function assumeNonMutatedObject(originalObject) {
+  assume(originalObject[LEVEL]).equals(undefined);
+}
+
 describe('format.errors (integration)', function () {
   it('logger.log(level, error)', (done) => {
     const logger = helpers.createLogger(function (info) {
       assumeExpectedInfo(info);
       done();
     }, format.errors());
+    const err = new Error('Errors lack .toJSON() lulz');
 
-    logger.log('info', new Error('Errors lack .toJSON() lulz'));
+    logger.log('info', err);
   });
 
   it('logger.log(level, error) [custom error properties]', (done) => {
@@ -51,7 +56,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
 
@@ -67,13 +72,15 @@ describe('format.errors (integration)', function () {
       thisIsMeta: true,
       anyValue: 'a string'
     };
+    const err = new Error('Errors lack .toJSON() lulz');
 
     const logger = helpers.createLogger(function (info) {
       assumeExpectedInfo(info, meta);
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
 
-    logger.log('info', new Error('Errors lack .toJSON() lulz'), meta);
+    logger.log('info', err, meta);
   });
 
   it('logger.log(level, error, meta) [custom error properties]', (done) => {
@@ -87,6 +94,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       }, meta));
+      assumeNonMutatedObject(err);
 
       done();
     }, format.errors());
@@ -103,14 +111,14 @@ describe('format.errors (integration)', function () {
       assumeExpectedInfo(info, {
         message: 'Caught error: Errors lack .toJSON() lulz'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.combine(
       format.errors(),
       format.printf(info => info.message)
     ));
-
-    logger.log('info', 'Caught error:', new Error('Errors lack .toJSON() lulz'));
+      const err = new Error('Errors lack .toJSON() lulz');
+    logger.log('info', 'Caught error:', err);
   });
 
   it('logger.log(level, msg, meta<error>) [custom error properties]', (done) => {
@@ -125,7 +133,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.combine(
       format.errors(),
@@ -138,10 +146,12 @@ describe('format.errors (integration)', function () {
   it('logger.<level>(error)', (done) => {
     const logger = helpers.createLogger(function (info) {
       assumeExpectedInfo(info);
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
+    const err = new Error('Errors lack .toJSON() lulz')
 
-    logger.info(new Error('Errors lack .toJSON() lulz'));
+    logger.info(err);
   });
 
   it('logger.<level>(error) [custom error properties]', (done) => {
@@ -150,7 +160,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
 
@@ -169,10 +179,11 @@ describe('format.errors (integration)', function () {
 
     const logger = helpers.createLogger(function (info) {
       assumeExpectedInfo(info, meta);
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
-
-    logger.info(new Error('Errors lack .toJSON() lulz'), meta);
+    const err = new Error('Errors lack .toJSON() lulz');
+    logger.info(err, meta);
   });
 
   it('logger.<level>(error, meta) [custom error properties]', (done) => {
@@ -186,7 +197,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       }, meta));
-
+      assumeNonMutatedObject(err);
       done();
     }, format.errors());
 
@@ -202,14 +213,15 @@ describe('format.errors (integration)', function () {
       assumeExpectedInfo(info, {
         message: 'Caught error: Errors lack .toJSON() lulz'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.combine(
       format.errors(),
       format.printf(info => info.message)
     ));
+    const err = new Error('Errors lack .toJSON() lulz');
 
-    logger.info('Caught error:', new Error('Errors lack .toJSON() lulz'));
+    logger.info('Caught error:', err);
   });
 
   it('logger.<level>(msg, meta<error>) [custom error properties]', (done) => {
@@ -224,7 +236,7 @@ describe('format.errors (integration)', function () {
         something: true,
         wut: 'another string'
       });
-
+      assumeNonMutatedObject(err);
       done();
     }, format.combine(
       format.errors(),
@@ -264,4 +276,4 @@ describe('format.errors (integration)', function () {
       throw err;
     }).catch(logger.error.bind(logger));
   });
-});
+  });