Repository: pinojs/pino
Pull request #802 (2020-03-30 11:06:14)

Add "silent" property with "noop" value to the pino instance
Hello this is a fix from issue raised in `pino-http` https://github.com/pinojs/pino-http/issues/79  
I'm not sure if this naive implementation is correct. Maybe we need to add `silent` to the levels list and update all of the methods which are related to the log levels. But if you ok with this implementation, I'll add tests to this PR.

jsumners: I'm not sure about this. We have always documented `silent` as a level value distinctly _not_ a logger method -- https://github.com/pinojs/pino/blob/529906ed868ec362d66b228dbc10bd201b766202/docs/api.md#loggerlevel-string-gettersetter

Changing that would mean a new semver major change, IMHO. I also think it would break from the standardized interface that is implemented, i.e. the log4j logger interface.

I think the better fix is at -- 
https://github.com/pinojs/pino-http/blob/eacc870e6d9d8e24608d27bd7bcda528ae162d47/logger.js#L53-L69
baterson: > Would you mind to add a bunch of unit tests?

What about the comment above? We can add check for "silent" level there https://github.com/pinojs/pino-http/blob/eacc870e6d9d8e24608d27bd7bcda528ae162d47/logger.js#L53-L69 
As @jsumners suggested.  
But if you all agree on this change, I'll going to add tests for this PR.
mcollina: I'm not necessarily sure about this fix because it's lacking unit tests. Specifically we need to check how it will work with child loggers, and if it interferers with changing the log level to "silent" and back at runtime.
baterson: @mcollina I added tests. Please tell me if I missed something.

jsumners: At a minimum, the docs would need to be updated. And I'd really like to know @davidmarkclements's thoughts.

Patch:
diff --git a/docs/api.md b/docs/api.md
index 7634768..3f0bfb3 100644
--- a/docs/api.md
+++ b/docs/api.md
@@ -11,6 +11,7 @@
   * [logger.warn()](#warn)
   * [logger.error()](#error)
   * [logger.fatal()](#fatal)
+  * [logger.silent()](#silent)
   * [logger.child()](#child)
   * [logger.bindings()](#bindings)
   * [logger.flush()](#flush)
@@ -560,6 +561,10 @@ the process crashes or exits.
 * See [`message` log method parameter](#message)
 * See [`...interpolationValues` log method parameter](#interpolationvalues)
 
+<a id="silent"><a>
+### `logger.silent()`
+
+Noop function.
 
 <a id="child"></a>
 ### `logger.child(bindings) => logger`
@@ -669,7 +674,7 @@ The logging level is a *minimum* level based on the associated value of that lev
 For instance if `logger.level` is `info` *(30)* then `info` *(30)*, `warn` *(40)*, `error` *(50)* and `fatal` *(60)* log methods will be enabled but the `trace` *(10)* and `debug` *(20)* methods, being less than 30, will not.
 
 The `silent` logging level is a specialized level which will disable all logging,
-there is no `silent` log method.
+the `silent` log method is a noop function.
 
 <a id="islevelenabled"></a>
 ### `logger.isLevelEnabled(level)`
diff --git a/lib/proto.js b/lib/proto.js
index 8e888a6..9c22093 100644
--- a/lib/proto.js
+++ b/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
   }
diff --git a/lib/tools.js b/lib/tools.js
index 7992c30..32ecff4 100644
--- a/lib/tools.js
+++ b/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)
diff --git a/pino.js b/pino.js
index 680d031..2c5a5f1 100644
--- a/pino.js
+++ b/pino.js
@@ -13,7 +13,8 @@ const {
   final,
   stringify,
   buildSafeSonicBoom,
-  buildFormatters
+  buildFormatters,
+  noop
 } = require('./lib/tools')
 const { version } = require('./lib/meta')
 const {
@@ -165,7 +166,8 @@ function pino (...args) {
     [mixinSym]: mixin,
     [chindingsSym]: chindings,
     [formattersSym]: allFormatters,
-    [hooksSym]: hooks
+    [hooksSym]: hooks,
+    silent: noop
   })
   Object.setPrototypeOf(instance, proto)
 


Test patch:
diff --git a/test/fixtures/pretty/formatters.js b/test/fixtures/pretty/formatters.js
new file mode 100644
index 0000000..c3a01a0
--- /dev/null
+++ b/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')
diff --git a/test/levels.test.js b/test/levels.test.js
index dd79970..a71cfd3 100644
--- a/test/levels.test.js
+++ b/test/levels.test.js
@@ -498,3 +498,55 @@ test('fatal method should call async when sync-flushing fails', ({ equal, fail,
   const instance = pino(stream)
   doesNotThrow(() => instance.fatal(messages[0]))
 })
+
+test('calling silent method on logger instance', async ({ fail }) => {
+  const instance = pino({ level: 'silent' }, sink((result, enc) => {
+    fail('no data should be logged')
+  }))
+  instance.silent('hello world')
+})
+
+test('calling silent method on child logger', async ({ fail }) => {
+  const child = pino({ level: 'silent' }, sink((result, enc) => {
+    fail('no data should be logged')
+  })).child({})
+  child.silent('hello world')
+})
+
+test('changing level from info to silent and back to info', async ({ is }) => {
+  const expected = {
+    level: 30,
+    msg: 'hello world'
+  }
+  const stream = sink()
+  const instance = pino({ level: 'info' }, stream)
+
+  instance.level = 'silent'
+  instance.info('hello world')
+  let result = stream.read()
+  is(result, null)
+
+  instance.level = 'info'
+  instance.info('hello world')
+  result = await once(stream, 'data')
+  check(is, result, expected.level, expected.msg)
+})
+
+test('changing level from info to silent and back to info in child logger', async ({ is }) => {
+  const expected = {
+    level: 30,
+    msg: 'hello world'
+  }
+  const stream = sink()
+  const child = pino({ level: 'info' }, stream).child({})
+
+  child.level = 'silent'
+  child.info('hello world')
+  let result = stream.read()
+  is(result, null)
+
+  child.level = 'info'
+  child.info('hello world')
+  result = await once(stream, 'data')
+  check(is, result, expected.level, expected.msg)
+})
diff --git a/test/metadata.test.js b/test/metadata.test.js
index 7fb1c9a..d5c3096 100644
--- a/test/metadata.test.js
+++ b/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()')
diff --git a/test/pretty.test.js b/test/pretty.test.js
index fa86649..be76b65 100644
--- a/test/pretty.test.js
+++ b/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')])