Fix bug Global serializer not invoked for strings when base: null (#…

…597)

* Fix bug Global serializer not invoked for strings when `base: null`

* Remove unused symbol

* remove sting interpolation

Co-Authored-By: yellowbrickc <yellowbrickc@users.noreply.github.com>

* Instead of cloning the object parameter, the messageKey prop will be set if needed.

lib/symbols.js

@@ -21,7 +21,7 @@ const stringifySym = Symbol('pino.stringify')
 const stringifiersSym = Symbol('pino.stringifiers')
 const endSym = Symbol('pino.end')
 const formatOptsSym = Symbol('pino.formatOpts')
-const messageKeyStringSym = Symbol('pino.messageKeyString')
+const messageKeySym = Symbol('pino.messageKey')
 
 const wildcardFirstSym = Symbol('pino.wildcardFirst')
 
@@ -49,7 +49,7 @@ module.exports = {
   stringifiersSym,
   endSym,
   formatOptsSym,
-  messageKeyStringSym,
+  messageKeySym,
   wildcardFirstSym,
   changeLevelNameSym,
   wildcardGsym,

lib/tools.js

@@ -9,7 +9,7 @@ const {
   chindingsSym,
   parsedChindingsSym,
   writeSym,
-  messageKeyStringSym,
+  messageKeySym,
   serializersSym,
   formatOptsSym,
   endSym,
@@ -68,14 +68,17 @@ function asString (str) {
 }
 
 function asJson (obj, msg, num, time) {
-  // to catch both null and undefined
-  const hasObj = obj !== undefined && obj !== null
-  const objError = hasObj && obj instanceof Error
-  msg = !msg && objError === true ? obj.message : msg || undefined
+  const objError = obj instanceof Error
+  const messageKey = this[messageKeySym]
+  if (obj === undefined || obj === null) obj = {}
+  if (msg) {
+    obj[messageKey] = msg
+  } else if (objError === true) {
+    obj[messageKey] = obj.message
+  }
   const stringify = this[stringifySym]
   const stringifiers = this[stringifiersSym]
   const end = this[endSym]
-  const messageKeyString = this[messageKeyStringSym]
   const chindings = this[chindingsSym]
   const serializers = this[serializersSym]
   var data = this[lsCacheSym][num] + time
@@ -85,49 +88,46 @@ function asJson (obj, msg, num, time) {
   data = data + chindings
 
   var value
-  if (hasObj === true) {
-    var notHasOwnProperty = obj.hasOwnProperty === undefined
-    if (objError === true) {
-      data += ',"type":"Error"'
-      if (obj.stack !== undefined) {
-        data += ',"stack":' + stringify(obj.stack)
-      }
-    }
-    // if global serializer is set, call it first
-    if (serializers[wildcardGsym]) {
-      obj = serializers[wildcardGsym](obj)
+  var notHasOwnProperty = obj.hasOwnProperty === undefined
+  if (objError === true) {
+    data += ',"type":"Error"'
+    if (obj.stack !== undefined) {
+      data += ',"stack":' + stringify(obj.stack)
     }
-    const wildcardStringifier = stringifiers[wildcardFirstSym]
-    for (var key in obj) {
-      value = obj[key]
-      if ((notHasOwnProperty || obj.hasOwnProperty(key)) && value !== undefined) {
-        value = serializers[key] ? serializers[key](value) : value
-
-        const stringifier = stringifiers[key] || wildcardStringifier
-
-        switch (typeof value) {
-          case 'undefined':
-          case 'function':
-            continue
-          case 'number':
-            /* eslint no-fallthrough: "off" */
-            if (Number.isFinite(value) === false) {
-              value = null
-            }
-            // this case explicity falls through to the next one
-          case 'boolean':
-            if (stringifier) value = stringifier(value)
-            data += ',"' + key + '":' + value
-            continue
-          case 'string':
-            value = (stringifier || asString)(value)
-            break
-          default:
-            value = (stringifier || stringify)(value)
-        }
-        if (value === undefined) continue
-        data += ',"' + key + '":' + value
+  }
+  if (serializers[wildcardGsym]) {
+    obj = serializers[wildcardGsym](obj)
+  }
+  const wildcardStringifier = stringifiers[wildcardFirstSym]
+  for (var key in obj) {
+    value = obj[key]
+    if ((notHasOwnProperty || obj.hasOwnProperty(key)) && value !== undefined) {
+      value = serializers[key] ? serializers[key](value) : value
+
+      const stringifier = stringifiers[key] || wildcardStringifier
+
+      switch (typeof value) {
+        case 'undefined':
+        case 'function':
+          continue
+        case 'number':
+          /* eslint no-fallthrough: "off" */
+          if (Number.isFinite(value) === false) {
+            value = null
+          }
+        // this case explicity falls through to the next one
+        case 'boolean':
+          if (stringifier) value = stringifier(value)
+          data += ',"' + key + '":' + value
+          continue
+        case 'string':
+          value = (stringifier || asString)(value)
+          break
+        default:
+          value = (stringifier || stringify)(value)
       }
+      if (value === undefined) continue
+      data += ',"' + key + '":' + value
     }
   }
 

pino.js

@@ -25,7 +25,7 @@ const {
   setLevelSym,
   endSym,
   formatOptsSym,
-  messageKeyStringSym,
+  messageKeySym,
   useLevelLabelsSym,
   changeLevelNameSym,
   useOnlyCustomLevelsSym
@@ -77,7 +77,6 @@ function pino (...args) {
   const formatOpts = redact
     ? { stringify: stringifiers[redactFmtSym] }
     : { stringify }
-  const messageKeyString = `,"${messageKey}":`
   const end = ',"v":' + LOG_VERSION + '}' + (crlf ? '\r\n' : '\n')
   const coreChindings = asChindings.bind(null, {
     [chindingsSym]: '',
@@ -106,7 +105,7 @@ function pino (...args) {
     [stringifiersSym]: stringifiers,
     [endSym]: end,
     [formatOptsSym]: formatOpts,
-    [messageKeyStringSym]: messageKeyString,
+    [messageKeySym]: messageKey,
     [serializersSym]: serializers,
     [chindingsSym]: chindings
   }

test/basic.test.js

@@ -279,6 +279,28 @@ test('set the base to null', async ({ is, same }) => {
   })
 })
 
+test('set the base to null and use a serializer', async ({ is, same }) => {
+  const stream = sink()
+  const instance = pino({
+    base: null,
+    serializers: {
+      [Symbol.for('pino.*')]: (input) => {
+        return Object.assign({}, input, { additionalMessage: 'using pino' })
+      }
+    }
+  }, stream)
+  instance.fatal('this is fatal too')
+  const result = await once(stream, 'data')
+  is(new Date(result.time) <= new Date(), true, 'time is greater than Date.now()')
+  delete result.time
+  same(result, {
+    level: 60,
+    msg: 'this is fatal too',
+    additionalMessage: 'using pino',
+    v: 1
+  })
+})
+
 test('throw if creating child without bindings', async ({ throws }) => {
   const stream = sink()
   const instance = pino(stream)

test/metadata.test.js

@@ -16,7 +16,7 @@ test('metadata works', async ({ ok, same, is }) => {
       is(30, this.lastLevel)
       is('a msg', this.lastMsg)
       ok(Number(this.lastTime) >= now)
-      same({ hello: 'world' }, this.lastObj)
+      same(this.lastObj, { hello: 'world', msg: 'a msg' })
       const result = JSON.parse(chunk)
       ok(new Date(result.time) <= new Date(), 'time is greater than Date.now()')
       delete result.time
@@ -41,7 +41,7 @@ test('child loggers works', async ({ ok, same, is }) => {
       is(child, this.lastLogger)
       is(30, this.lastLevel)
       is('a msg', this.lastMsg)
-      same({ from: 'child' }, this.lastObj)
+      same(this.lastObj, { from: 'child', msg: 'a msg' })
       const result = JSON.parse(chunk)
       ok(new Date(result.time) <= new Date(), 'time is greater than Date.now()')
       delete result.time