fix(metadata precedence) - fix metadata override issues

.editorconfig

@@ -6,7 +6,6 @@ root = true
 # default configuration
 [*]
 charset = utf-8
-end_of_line = crlf
 trim_trailing_whitespace = true
 insert_final_newline = true
 indent_style = space

.eslintrc

@@ -2,6 +2,7 @@
   "extends": "@dabh/eslint-config-populist",
   "rules": {
     "one-var": ["error", { "var": "never", "let": "never", "const": "never" }],
+    "semi": "error",
     "strict": 0
   },
   "parserOptions": {

.nycrc.yml

@@ -4,5 +4,5 @@ reporter:
 check-coverage: true
 branches: 61.51
 lines: 70.85
-functions: 73.21
+functions: 73.08
 statements: 70.54

lib/winston/logger.js

@@ -9,14 +9,15 @@
 
 const { Stream, Transform } = require('readable-stream');
 const asyncForEach = require('async/forEach');
-const { LEVEL, SPLAT } = require('triple-beam');
+const { LEVEL, SPLAT, MESSAGE } = require('triple-beam');
 const isStream = require('is-stream');
 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 config = require('./config');
+const jsonStringify = require('safe-stable-stringify');
 
 /**
  * Captures the number of format (i.e. %s strings) in a given string.
@@ -42,30 +43,12 @@ class Logger extends Transform {
     this.configure(options);
   }
 
-  child(defaultRequestMetadata) {
+  child(childMetadata) {
     const logger = this;
+    const clonedParentMetadata = JSON.parse(jsonStringify(this.defaultMeta));
     return Object.create(logger, {
-      write: {
-        value: function (info) {
-          const infoClone = Object.assign(
-            {},
-            defaultRequestMetadata,
-            info
-          );
-
-          // Object.assign doesn't copy inherited Error
-          // properties so we have to do that explicitly
-          //
-          // Remark (indexzero): we should remove this
-          // since the errors format will handle this case.
-          //
-          if (info instanceof Error) {
-            infoClone.stack = info.stack;
-            infoClone.message = info.message;
-          }
-
-          logger.write(infoClone);
-        }
+      defaultMeta: {
+        value: Object.assign({}, clonedParentMetadata, childMetadata)
       }
     });
   }
@@ -288,6 +271,10 @@ class Logger extends Transform {
       info[LEVEL] = info.level;
     }
 
+    if (!info[MESSAGE]) {
+      info[MESSAGE] = info.message;
+    }
+
     // Remark: really not sure what to do here, but this has been reported as
     // very confusing by pre winston@2.0.0 users as quite confusing when using
     // custom levels.
@@ -647,7 +634,9 @@ class Logger extends Transform {
 
   _addDefaultMeta(msg) {
     if (this.defaultMeta) {
-      Object.assign(msg, this.defaultMeta);
+      // The msg must be cloned as it is being mutated, but any metadata provided with the msg takes precedence over default
+      const msgClone = JSON.parse(jsonStringify(msg));
+      Object.assign(msg, this.defaultMeta, msgClone);
     }
   }
 }

lib/winston/profiler.js

@@ -21,6 +21,8 @@ module.exports = class Profiler {
    * @private
    */
   constructor(logger) {
+    // TODO there is no restriction on what the Profiler considers a Logger. As such there is no guarantees it adheres
+    //   to the proper interface. This needs to hardened.
     if (!logger) {
       throw new Error('Logger is required for profiling.');
     }
@@ -32,7 +34,8 @@ module.exports = class Profiler {
   /**
    * Ends the current timer (i.e. Profiler) instance and logs the `msg` along
    * with the duration since creation.
-   * @returns {mixed} - TODO: add return description.
+   * @returns {boolean} - `false` if the logger stream wishes for the calling code to wait for the 'drain' event to be
+   *   emitted before continuing to write additional data; otherwise `true`
    * @private
    */
   done(...args) {
@@ -45,7 +48,7 @@ module.exports = class Profiler {
     const info = typeof args[args.length - 1] === 'object' ? args.pop() : {};
     info.level = info.level || 'info';
     info.durationMs = (Date.now()) - this.start;
-
+    if (this.logger._addDefaultMeta) this.logger._addDefaultMeta(info);
     return this.logger.write(info);
   }
 };

package.json

@@ -60,6 +60,7 @@
   "types": "./index.d.ts",
   "scripts": {
     "lint": "eslint lib/*.js lib/winston/*.js lib/winston/**/*.js --resolve-plugins-relative-to ./node_modules/@dabh/eslint-config-populist",
+    "lint:fix": "npm run lint -- --fix",
     "test": "mocha",
     "test:coverage": "nyc npm run test:unit",
     "test:unit": "mocha test/unit",

test/helpers/mocks/mock-transport.js

@@ -1,9 +1,10 @@
 const stream = require('stream')
 const winston = require('../../../lib/winston');
+const {Writable} = require("stream");
 
 /**
  * Returns a new Winston transport instance which will invoke
- * the `write` method on each call to `.log`
+ * the `write` method on each call to `.log`
  *
  * @param {function} write Write function for the specified stream
  * @returns {StreamTransportInstance} A transport instance
@@ -17,6 +18,23 @@ function createMockTransport(write) {
   return new winston.transports.Stream({ stream: writeable })
 }
 
+/**
+ * Returns a valid Winston transport that writes to the passed array object
+ * @param array Array to be used to store the "written" chunks
+ * @returns {winston.transports.Stream}
+ */
+function inMemory(array, options = {}) {
+  const memoryStream = new Writable({
+    objectMode: true,
+    write: (chunk, encoding, next) => {
+      array.push(chunk);
+      next()
+    }
+  });
+  return new winston.transports.Stream({stream: memoryStream, ...options})
+}
+
 module.exports = {
-  createMockTransport
+  createMockTransport,
+  inMemory
 };