Add formatters for core log components (pinojs#775)

* WIP: added bindings and levels serializers * Addressed comments * Fixed test * Moved from custom srializers to formatters * Use stricter check in genLsCache * Updated test * Addressed comments * Added log formatter and removed pino.* serializer * Updated test * Use factory for formatters object * Added deprecations messages - deprecated useLevelLabels - deprecated changeLevelName - deprecated pino.* serializer * Updated test * Addressed comments * Fix test * Improve code coverage * Fixed levelKey handling * Updated test * Addressed comments * Updated test * Added formatters benchmarks * Rename test * 100% code coverage * Added formatters to benchmark runner * Updated documentation * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Update docs/api.md Co-Authored-By: James Sumners <[email protected]> * Addressed comments Co-authored-by: James Sumners <[email protected]> Co-authored-by: Matteo Collina <[email protected]>
larenelg · Mar 18, 2020 · f3ab176 · f3ab176
1 parent 5c85000
commit f3ab176
Show file tree

Hide file tree

Showing 15 changed files with 716 additions and 125 deletions.
diff --git a/benchmarks/formatters.bench.js b/benchmarks/formatters.bench.js
@@ -0,0 +1,50 @@
+'use strict'
+
+const formatters = {
+  level (label, number) {
+    return {
+      log: {
+        level: label
+      }
+    }
+  },
+  bindings (bindings) {
+    return {
+      process: {
+        pid: bindings.pid
+      },
+      host: {
+        name: bindings.hostname
+      }
+    }
+  },
+  log (obj) {
+    return { foo: 'bar', ...obj }
+  }
+}
+
+const bench = require('fastbench')
+const pino = require('../')
+delete require.cache[require.resolve('../')]
+const pinoNoFormatters = require('../')(pino.destination('/dev/null'))
+delete require.cache[require.resolve('../')]
+const pinoFormatters = require('../')({ formatters }, pino.destination('/dev/null'))
+
+const max = 10
+
+const run = bench([
+  function benchPinoNoFormatters (cb) {
+    for (var i = 0; i < max; i++) {
+      pinoNoFormatters.info({ hello: 'world' })
+    }
+    setImmediate(cb)
+  },
+  function benchPinoFormatters (cb) {
+    for (var i = 0; i < max; i++) {
+      pinoFormatters.info({ hello: 'world' })
+    }
+    setImmediate(cb)
+  }
+], 10000)
+
+run(run)
diff --git a/benchmarks/utils/runbench.js b/benchmarks/utils/runbench.js
@@ -22,6 +22,7 @@ function usage () {
     ・child      ⁃ child from a parent
     ・child-child ⁃ child from a child
     ・child-creation ⁃ child constructor
+    ・formatters ⁃ difference between with or without formatters
 
     Example:
 
@@ -46,7 +47,8 @@ const benchmarks = {
   'long-string': 'long-string.bench.js',
   child: 'child.bench.js',
   'child-child': 'child-child.bench.js',
-  'child-creation': 'child-creation.bench.js'
+  'child-creation': 'child-creation.bench.js',
+  formatters: 'formatters.bench.js'
 }
 
 function runBenchmark (name, done) {

diff --git a/docs/api.md b/docs/api.md
@@ -137,6 +137,58 @@ If an object is supplied, three options can be specified:
 * See the [redaction ⇗](/docs/redaction.md) documentation.
 * See [fast-redact#caveat ⇗](http://github.com/davidmarkclements/fast-redact#caveat)
 
+<a id=opt-formatters></a>
+#### `formatters` (Object)
+
+An object containing functions for formatting the shape of the log lines.
+These functions should return a JSONifiable object and
+should never throw. These functions allow for full customization of
+the resulting log lines. For example, they can be used to change
+the level key name or to enrich the default metadata.
+
+##### `level`
+
+Changes the shape of the log level. The default shape is `{ level: number }`.
+The function takes two arguments, the label of the level (e.g. `'info'`)
+and the numeric value (e.g. `30`).
+
+```js
+const formatters = {
+  level (label, number) {
+    return { level: number }
+  }
+}
+```
+
+##### `bindings`
+
+Changes the shape of the bindings. The default shape is `{ pid, hostname }`.
+The function takes a single argument, the bindings object. It will
+be called every time a child logger is created.
+
+```js
+const formatters = {
+  bindings (bindings) {
+    return { pid: bindings.pid, hostname: bindings.hostname }
+  }
+}
+```
+
+##### `log`
+
+Changes the shape of the log object. This function will be called every time
+one of the log methods (such as `.info`) is called. All arguments passed to the
+log method, except the message, will be pass to this function. By default it does
+not change the shape of the log object.
+
+```js
+const formatters = {
+  log (object) {
+    return object
+  }
+}
+```
+
 <a id=opt-serializers></a>
 #### `serializers` (Object)
 
@@ -149,12 +201,9 @@ matching the exact key of a serializer will be serialized using the defined seri
 
 * See [pino.stdSerializers](#pino-stdserializers)
 
-##### `serializers[Symbol.for('pino.*')]` (Function)
-
-Default: `undefined`
+##### `serializers[Symbol.for('pino.*')]` (Function) - DEPRECATED
 
-The `serializers` object may contain a key which is the global symbol: `Symbol.for('pino.*')`.
-This will act upon the complete log object rather than corresponding to a particular key.
+Use `formatters.log` instead.
 
 #### `base` (Object)
 
@@ -243,30 +292,18 @@ npm install pino-pretty
 ```
 
 <a id="useLevelLabels"></a>
-#### `useLevelLabels` (Boolean)
+#### `useLevelLabels` (Boolean) - DEPRECATED
 
-Default: `false`
-
-Enables printing of level labels instead of level values in the printed logs.
-Warning: this option may not be supported by downstream transports.
+Use `formatters.level` instead. This will be removed in v7.
 
 <a id="changeLevelName"></a>
 #### `changeLevelName` (String) - DEPRECATED
-Use `levelKey` instead. This will be removed in v7.
+Use `formatters.level` instead. This will be removed in v7.
 
 <a id="levelKey"></a>
-#### `levelKey` (String)
+#### `levelKey` (String) - DEPRECATED
 
-Default: `'level'`
-
-Changes the property `level` to any string value you pass in:
-```js
-const logger = pino({
-  levelKey: 'priority'
-})
-logger.info('hello world')
-// {"priority":30,"time":1531257112193,"msg":"hello world","pid":55956,"hostname":"x"}
-```
+Use `formatters.level` instead. This will be removed in v7.
 
 #### `browser` (Object)
 

diff --git a/lib/levels.js b/lib/levels.js
@@ -1,12 +1,12 @@
 'use strict'
+/* eslint no-prototype-builtins: 0 */
 const flatstr = require('flatstr')
 const {
   lsCacheSym,
   levelValSym,
-  useLevelLabelsSym,
-  levelKeySym,
   useOnlyCustomLevelsSym,
-  streamSym
+  streamSym,
+  formattersSym
 } = require('./symbols')
 const { noop, genLog } = require('./tools')
 
@@ -49,13 +49,14 @@ const initialLsCache = Object.keys(nums).reduce((o, k) => {
 }, {})
 
 function genLsCache (instance) {
-  const levelName = instance[levelKeySym]
-  instance[lsCacheSym] = Object.keys(instance.levels.labels).reduce((o, k) => {
-    o[k] = instance[useLevelLabelsSym]
-      ? `{"${levelName}":"${instance.levels.labels[k]}"`
-      : flatstr(`{"${levelName}":` + Number(k))
-    return o
-  }, Object.assign({}, instance[lsCacheSym]))
+  const formatter = instance[formattersSym].level
+  const { labels } = instance.levels
+  const cache = {}
+  for (const label in labels) {
+    const level = formatter(labels[label], Number(label))
+    cache[label] = JSON.stringify(level).slice(0, -1)
+  }
+  instance[lsCacheSym] = cache
   return instance
 }
 

diff --git a/lib/proto.js b/lib/proto.js
@@ -13,12 +13,12 @@ const {
   chindingsSym,
   mixinSym,
   asJsonSym,
-  messageKeySym,
   writeSym,
   timeSym,
   timeSliceIndexSym,
   streamSym,
   serializersSym,
+  formattersSym,
   useOnlyCustomLevelsSym,
   needsMetadataGsym
 } = require('./symbols')
@@ -33,7 +33,8 @@ const {
 } = require('./levels')
 const {
   asChindings,
-  asJson
+  asJson,
+  buildFormatters
 } = require('./tools')
 const {
   version
@@ -65,10 +66,13 @@ Object.setPrototypeOf(prototype, EventEmitter.prototype)
 
 module.exports = prototype
 
+const resetChildingsFormatter = bindings => bindings
 function child (bindings) {
-  const { level } = this
+  if (!bindings) {
+    throw Error('missing bindings for child Pino')
+  }
   const serializers = this[serializersSym]
-  const chindings = asChindings(this, bindings)
+  const formatters = this[formattersSym]
   const instance = Object.create(this)
   if (bindings.hasOwnProperty('serializers') === true) {
     instance[serializersSym] = Object.create(null)
@@ -91,13 +95,27 @@ function child (bindings) {
       instance[serializersSym][bks] = bindings.serializers[bks]
     }
   } else instance[serializersSym] = serializers
+  if (bindings.hasOwnProperty('formatters')) {
+    const { level, bindings: chindings, log } = bindings.formatters
+    instance[formattersSym] = buildFormatters(
+      level || formatters.level,
+      chindings || resetChildingsFormatter,
+      log || formatters.log
+    )
+  } else {
+    instance[formattersSym] = buildFormatters(
+      formatters.level,
+      resetChildingsFormatter,
+      formatters.log
+    )
+  }
   if (bindings.hasOwnProperty('customLevels') === true) {
     assertNoLevelCollisions(this.levels, bindings.customLevels)
     instance.levels = mappings(bindings.customLevels, instance[useOnlyCustomLevelsSym])
     genLsCache(instance)
   }
-  instance[chindingsSym] = chindings
-  const childLevel = bindings.level || level
+  instance[chindingsSym] = asChindings(instance, bindings)
+  const childLevel = bindings.level || this.level
   instance[setLevelSym](childLevel)
 
   return instance
@@ -119,20 +137,16 @@ function setBindings (newBindings) {
 
 function write (_obj, msg, num) {
   const t = this[timeSym]()
-  const messageKey = this[messageKeySym]
   const mixin = this[mixinSym]
   const objError = _obj instanceof Error
   var obj
 
   if (_obj === undefined || _obj === null) {
     obj = mixin ? mixin() : {}
-    obj[messageKey] = msg
   } else {
     obj = Object.assign(mixin ? mixin() : {}, _obj)
-    if (msg) {
-      obj[messageKey] = msg
-    } else if (objError) {
-      obj[messageKey] = _obj.message
+    if (!msg && objError) {
+      msg = _obj.message
     }
 
     if (objError) {
@@ -143,7 +157,7 @@ function write (_obj, msg, num) {
     }
   }
 
-  const s = this[asJsonSym](obj, num, t)
+  const s = this[asJsonSym](obj, msg, num, t)
 
   const stream = this[streamSym]
   if (stream[needsMetadataGsym] === true) {

diff --git a/lib/symbols.js b/lib/symbols.js
@@ -4,7 +4,6 @@ const setLevelSym = Symbol('pino.setLevel')
 const getLevelSym = Symbol('pino.getLevel')
 const levelValSym = Symbol('pino.levelVal')
 const useLevelLabelsSym = Symbol('pino.useLevelLabels')
-const levelKeySym = Symbol('pino.levelKey')
 const useOnlyCustomLevelsSym = Symbol('pino.useOnlyCustomLevels')
 const mixinSym = Symbol('pino.mixin')
 
@@ -31,7 +30,7 @@ const wildcardFirstSym = Symbol('pino.wildcardFirst')
 // public symbols, no need to use the same pino
 // version for these
 const serializersSym = Symbol.for('pino.serializers')
-const wildcardGsym = Symbol.for('pino.*')
+const formattersSym = Symbol.for('pino.formatters')
 const needsMetadataGsym = Symbol.for('pino.metadata')
 
 module.exports = {
@@ -57,8 +56,7 @@ module.exports = {
   messageKeySym,
   nestedKeySym,
   wildcardFirstSym,
-  levelKeySym,
-  wildcardGsym,
   needsMetadataGsym,
-  useOnlyCustomLevelsSym
+  useOnlyCustomLevelsSym,
+  formattersSym
 }