Support formatters.log on pretty print (#809)

* Support formatters.log on pretty print

* Make msg available on pretty print with formatters.log applied

* Ensure object exists

* Re-add lastMsg tests

lib/proto.js

@@ -163,6 +163,7 @@ function write (_obj, msg, num) {
   if (stream[needsMetadataGsym] === true) {
     stream.lastLevel = num
     stream.lastObj = obj
+    stream.lastMsg = msg
     stream.lastTime = t.slice(this[timeSliceIndexSym])
     stream.lastLogger = this // for child loggers
   }

lib/tools.js

@@ -238,12 +238,21 @@ function prettifierMetaWrapper (pretty, dest) {
       }
 
       var lastObj = this.lastObj
+      var lastMsg = this.lastMsg
       var errorProps = null
 
+      const formatters = lastLogger[formattersSym]
+      const formattedObj = formatters.log ? formatters.log(lastObj) : lastObj
+
+      const messageKey = lastLogger[messageKeySym]
+      if (lastMsg && formattedObj && !formattedObj.hasOwnProperty(messageKey)) {
+        formattedObj[messageKey] = lastMsg
+      }
+
       const obj = Object.assign({
         level: this.lastLevel,
         time
-      }, lastObj, errorProps)
+      }, formattedObj, errorProps)
 
       const serializers = lastLogger[serializersSym]
       const keys = Object.keys(serializers)

test/fixtures/pretty/formatters.js

@@ -0,0 +1,13 @@
+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,
+  formatters: {
+    log (obj) {
+      return { foo: 'formatted_' + obj.foo }
+    }
+  }
+})
+log.info({ foo: 'bar' }, 'h')

test/metadata.test.js

@@ -14,6 +14,7 @@ test('metadata works', async ({ ok, same, is }) => {
     write (chunk) {
       is(instance, this.lastLogger)
       is(30, this.lastLevel)
+      is('a msg', this.lastMsg)
       ok(Number(this.lastTime) >= now)
       same(this.lastObj, { hello: 'world', msg: 'a msg' })
       const result = JSON.parse(chunk)
@@ -38,6 +39,7 @@ test('child loggers works', async ({ ok, same, is }) => {
     write (chunk) {
       is(child, this.lastLogger)
       is(30, this.lastLevel)
+      is('a msg', this.lastMsg)
       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()')
@@ -63,6 +65,7 @@ test('without object', async ({ ok, same, is }) => {
     write (chunk) {
       is(instance, this.lastLogger)
       is(30, this.lastLevel)
+      is('a msg', this.lastMsg)
       same({ msg: 'a msg' }, this.lastObj)
       const result = JSON.parse(chunk)
       ok(new Date(result.time) <= new Date(), 'time is greater than Date.now()')

test/pretty.test.js

@@ -112,6 +112,19 @@ test('parses and outputs chindings', async ({ is, isNot }) => {
   is(strip(actual).match(/a: 1/g).length, 3)
 })
 
+test('applies formatters', async ({ is, isNot }) => {
+  var actual = ''
+  const child = execa(process.argv[0], [join(__dirname, 'fixtures', 'pretty', 'formatters.js')])
+
+  child.stdout.pipe(writer((s, enc, cb) => {
+    actual += s
+    cb()
+  }))
+  await once(child, 'close')
+  isNot(strip(actual).match(/\(123456 on abcdefghijklmnopqr\): h/), null)
+  isNot(strip(actual).match(/foo: "formatted_bar"/), null)
+})
+
 test('parses and outputs chindings with serializer', async ({ is, isNot }) => {
   var actual = ''
   const child = execa(process.argv[0], [join(__dirname, 'fixtures', 'pretty', 'child-with-serializer.js')])