Consistent handling of meta with (and without) interpolation in winst…

…on & logform (#1552)

* [doc fix] Build on the work from #1485 fixes.

* [tiny] Formatting changes.

* [fix test] Updated tests to latest (consistent) semantics.

* [dist] Update to `logform@2.0.0` and `winston-transport@4.3.0`.

* [doc] Document all possible permuations for splat.

examples/splat.js

@@ -0,0 +1,86 @@
+const winston = require('../');
+let { format } = winston;
+
+/*
+ * Simple helper for stringifying all remaining
+ * properties.
+ */
+function rest(info) {
+  return JSON.stringify(Object.assign({}, info, {
+    level: undefined,
+    message: undefined,
+    splat: undefined,
+    label: undefined
+  }));
+}
+
+let logger = winston.createLogger({
+  transports: [new winston.transports.Console({ level: 'info' })],
+  format: format.combine(
+    format.splat(),
+    format.printf(info => `[${info.label}] ${info.message} ${rest(info)}`)
+  )
+});
+
+logger.log(
+  'info',
+  'any message',
+  {
+    label: 'label!',
+    extra: true
+  }
+);
+
+logger.log(
+  'info',
+  'let\'s %s some %s',
+  'interpolate',
+  'splat parameters',
+  {
+    label: 'label!',
+    extra: true
+  }
+);
+
+logger.log(
+  'info',
+  'first is a string %s [[%j]]',
+  'behold a string',
+  { beAware: 'this will interpolate' },
+  {
+    label: 'label!',
+    extra: true
+  }
+);
+
+logger.log(
+  'info',
+  'first is an object [[%j]]',
+  { beAware: 'this will interpolate' },
+  {
+    label: 'label!',
+    extra: true
+  }
+);
+
+//
+// Non-enumerable properties (such as "message" and "stack" in Error
+// instances) will not be merged into any `info`.
+//
+const terr = new Error('lol please stop doing this');
+terr.label = 'error';
+terr.extra = true;
+logger.log(
+  'info',
+  'any message',
+  terr
+);
+
+logger.log(
+  'info',
+  'let\'s %s some %s',
+  'interpolate',
+  'splat parameters',
+  terr
+);
+

lib/winston/logger.js

@@ -17,6 +17,14 @@ const Profiler = require('./profiler');
 const { warn } = require('./common');
 const config = require('./config');
 
+/**
+ * Captures the number of format (i.e. %s strings) in a given string.
+ * Based on `util.format`, see Node.js source:
+ * https://github.com/nodejs/node/blob/b1c8f15c5f169e021f7c46eb7b219de95fe97603/lib/util.js#L201-L230
+ * @type {RegExp}
+ */
+const formatRegExp = /%[scdjifoO%]/g;
+
 /**
  * TODO: add class description.
  * @type {Logger}
@@ -41,9 +49,9 @@ class Logger extends Transform {
       write: {
         value: function (info) {
           const infoClone = Object.assign(
-              {},
-              defaultRequestMetadata,
-              info
+            {},
+            defaultRequestMetadata,
+            info
           );
 
           // Object.assign doesn't copy inherited Error properties so we have to do that explicitly
@@ -157,11 +165,15 @@ class Logger extends Transform {
    *    // Supports the existing API:
    *    logger.log('info', 'Hello world', { custom: true });
    *    logger.log('info', new Error('Yo, it\'s on fire'));
+   *
+   *    // Requires winston.format.splat()
    *    logger.log('info', '%s %d%%', 'A string', 50, { thisIsMeta: true });
    *
    *    // And the new API with a single JSON literal:
    *    logger.log({ level: 'info', message: 'Hello world', custom: true });
    *    logger.log({ level: 'info', message: new Error('Yo, it\'s on fire') });
+   *
+   *    // Also requires winston.format.splat()
    *    logger.log({
    *      level: 'info',
    *      message: '%s %d%%',
@@ -198,21 +210,32 @@ class Logger extends Transform {
 
     const [meta] = splat;
     if (typeof meta === 'object' && meta !== null) {
-      this.write(Object.assign({}, meta, {
-        [LEVEL]: level,
-        [SPLAT]: splat.slice(0),
-        level,
-        message: msg
-      },
-      this.defaultMeta));
+      // Extract tokens, if none available default to empty array to
+      // ensure consistancy in expected results
+      const tokens = msg && msg.match && msg.match(formatRegExp);
+
+      if (!tokens) {
+        this.write(Object.assign({}, meta, {
+          [LEVEL]: level,
+          [SPLAT]: splat,
+          level,
+          message: msg
+        }, this.defaultMeta));
+      } else {
+        this.write(Object.assign({}, {
+          [LEVEL]: level,
+          [SPLAT]: splat,
+          level,
+          message: msg
+        }, this.defaultMeta));
+      }
     } else {
       this.write(Object.assign({}, {
         [LEVEL]: level,
         [SPLAT]: splat,
         level,
         message: msg
-      },
-      this.defaultMeta));
+      }, this.defaultMeta));
     }
 
     return this;