Repository: pinojs/pino (js)

Issue:
Missing message when using with pretty print
The latest version of pino (5.12.1), this pull request to be exact https://github.com/pinojs/pino/pull/635, causes message to be undefined when passing to pretty-print if logging using only Object like the following:

```
const logger = pino({
  prettyPrint: true,
})
logger.info({ msg: 'test!' })
```

Expected Output:
```
[1554452604021] INFO  (3605 on re7eal-VirtualBox): test!
```

Output:
```
[1554452604021] INFO  (3605 on re7eal-VirtualBox): 
```

Pull request description:
Fix 636
Fixes #636.

Patch:
diff --git a/lib/proto.js b/lib/proto.js
index 4064c12..15e4e63 100644
--- a/lib/proto.js
+++ b/lib/proto.js
@@ -9,6 +9,7 @@ const {
   getLevelSym,
   chindingsSym,
   asJsonSym,
+  messageKeySym,
   writeSym,
   timeSym,
   streamSym,
@@ -95,12 +96,38 @@ function bindings () {
   return bindingsFromJson
 }
 
-function write (obj, msg, num) {
+function write (_obj, msg, num) {
   const t = this[timeSym]()
-  const s = this[asJsonSym](obj, msg, num, t)
+  const messageKey = this[messageKeySym]
+  const objError = _obj instanceof Error
+  var obj
+
+  if (_obj === undefined || _obj === null) {
+    obj = {}
+    obj[messageKey] = msg
+  } else {
+    obj = Object.assign({}, _obj)
+    if (msg) {
+      obj[messageKey] = msg
+    } else if (objError) {
+      obj[messageKey] = _obj.message
+    }
+
+    if (objError) {
+      obj.stack = _obj.stack
+      if (!obj.type) {
+        obj.type = 'Error'
+      }
+    }
+  }
+
+  const s = this[asJsonSym](obj, num, t, objError)
+
   const stream = this[streamSym]
   if (stream[needsMetadataGsym] === true) {
     stream.lastLevel = num
+    // TODO remove in the next major release,
+    // it is not needed anymore
     stream.lastMsg = msg
     stream.lastObj = obj
     stream.lastTime = t.slice(8)
diff --git a/lib/tools.js b/lib/tools.js
index b27324c..ccb7e3c 100644
--- a/lib/tools.js
+++ b/lib/tools.js
@@ -9,7 +9,6 @@ const {
   chindingsSym,
   parsedChindingsSym,
   writeSym,
-  messageKeySym,
   serializersSym,
   formatOptsSym,
   endSym,
@@ -67,19 +66,7 @@ function asString (str) {
   return point < 32 ? JSON.stringify(str) : '"' + result + '"'
 }
 
-function asJson (obj, msg, num, time) {
-  const objError = obj instanceof Error
-  const messageKey = this[messageKeySym]
-  if (obj === undefined || obj === null) obj = {}
-  let oldMessage
-  if (msg) {
-    if (obj.hasOwnProperty(messageKey)) {
-      oldMessage = obj[messageKey]
-    }
-    obj[messageKey] = msg
-  } else if (objError === true) {
-    obj[messageKey] = obj.message
-  }
+function asJson (obj, num, time) {
   const stringify = this[stringifySym]
   const stringifiers = this[stringifiersSym]
   const end = this[endSym]
@@ -93,12 +80,6 @@ function asJson (obj, msg, num, time) {
 
   var value
   var notHasOwnProperty = obj.hasOwnProperty === undefined
-  if (objError === true) {
-    data += ',"type":"Error"'
-    if (obj.stack !== undefined) {
-      data += ',"stack":' + stringify(obj.stack)
-    }
-  }
   if (serializers[wildcardGsym]) {
     obj = serializers[wildcardGsym](obj)
   }
@@ -135,15 +116,6 @@ function asJson (obj, msg, num, time) {
     }
   }
 
-  if (oldMessage !== undefined) {
-    obj[messageKey] = oldMessage
-  } else {
-    // This delete is not going to cause problems,
-    // because the messageKey is the last property
-    // added. Turbofan <3
-    delete obj[messageKey]
-  }
-
   return data + end
 }
 
@@ -239,20 +211,10 @@ function prettifierMetaWrapper (pretty, dest) {
       }
 
       var lastObj = this.lastObj
-      var msg = this.lastMsg
       var errorProps = null
 
-      if (lastObj instanceof Error) {
-        msg = msg || lastObj.message
-        errorProps = {
-          type: 'Error',
-          stack: lastObj.stack
-        }
-      }
-
       const obj = Object.assign({
         level: this.lastLevel,
-        msg,
         time
       }, chindings, lastObj, errorProps)
 


Test patch:
diff --git a/test/fixtures/pretty/obj-msg-prop.js b/test/fixtures/pretty/obj-msg-prop.js
new file mode 100644
index 0000000..0869dae
--- /dev/null
+++ b/test/fixtures/pretty/obj-msg-prop.js
@@ -0,0 +1,6 @@
+global.process = { __proto__: process, pid: 123456 }
+Date.now = function () { return 1459875739796 }
+require('os').hostname = function () { return 'abcdefghijklmnopqr' }
+var pino = require(require.resolve('./../../../'))
+var log = pino({ prettyPrint: true })
+log.info({ msg: 'hello' })
diff --git a/test/metadata.test.js b/test/metadata.test.js
index 48d138a..d902d3c 100644
--- a/test/metadata.test.js
+++ b/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(this.lastObj, { hello: 'world' })
+      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(this.lastObj, { from: 'child' })
+      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
@@ -68,7 +68,7 @@ test('without object', async ({ ok, same, is }) => {
       is(instance, this.lastLogger)
       is(30, this.lastLevel)
       is('a msg', this.lastMsg)
-      is(null, this.lastObj)
+      same({ msg: 'a msg' }, this.lastObj)
       const result = JSON.parse(chunk)
       ok(new Date(result.time) <= new Date(), 'time is greater than Date.now()')
       delete result.time
diff --git a/test/pretty.test.js b/test/pretty.test.js
index 179ba09..066e934 100644
--- a/test/pretty.test.js
+++ b/test/pretty.test.js
@@ -248,3 +248,15 @@ test('final works without prior logging', async ({ isNot }) => {
   isNot(actual.match(/WARN\s+: pino.final with prettyPrint does not support flushing/), null)
   isNot(actual.match(/INFO\s+\(123456 on abcdefghijklmnopqr\): beforeExit/), null)
 })
+
+test('works as expected with an object with the msg prop', async ({ isNot }) => {
+  var actual = ''
+  const child = execa(process.argv[0], [join(__dirname, 'fixtures', 'pretty', 'obj-msg-prop.js')])
+
+  child.stdout.pipe(writer((s, enc, cb) => {
+    actual += s
+    cb()
+  }))
+  await once(child, 'close')
+  isNot(actual.match(/\(123456 on abcdefghijklmnopqr\): hello/), null)
+})