Repository: pinojs/pino
Pull request #775 (2020-02-18 14:53:03)

Add formatters for core log components
Hello everyone!
This pr is the continuation of the proposal in https://github.com/pinojs/pino/issues/764.
Once I wrote the first PoC, I've changed quite a bit the approach. Following a brief explanation of what ported me to write this proposal.

As you know, one of the reasons why Pino is very fast™ is because there is a lot of caching going on, which makes impossible to have a single endpoint where a user can specify a format of the logs. Probably the best solution to this problem is https://github.com/pinojs/pino/pull/614.
The most powerful tool that Pino is offering for addressing the "format" problem, are the serializers. The only issue is that the serializers are for everything that will be passed in the pino methods, but not for the base log structure, such as the log level and all the bindings.
This proposal adds a serializer also for the level handling and the bindings, and it works as follows:
```js
const {
  bindingsSerializerSym,
  levelSerializerSym
} = require('./lib/symbols')

const pino = require('./')({
  serializers: {
    [bindingsSerializerSym] (bindings) {
      return {
        process: { pid: bindings.pid },
        hostname: bindings.hostname
      }
    },
    [levelSerializerSym] (label, number) {
      return {
        log: { level: label }
      }
    }
  }
})

pino.info('hello world')

const child = pino.child({
  foo: 'bar',
  nested: { object: true },
  serializers: {
    [bindingsSerializerSym] (bindings) {
      return { hello: 'world', ...bindings }
    }
  }
})

child.info('test')
```
The produced logs are:
```
{"log":{"level":"info"},"time":1582036600545,"process":{"pid":38765},"hostname":"Skadi.local","msg":"hello world"}
{"log":{"level":"info"},"time":1582036600546,"process":{"pid":38765},"hostname":"Skadi.local","process":{"pid":38765},"hostname":"Skadi.local","hello":"world","foo":"bar","nested":{"object":true},"msg":"test"}
```

What I like about this approach is that it's not "yet another option", but it's a feature and Pino itself is the first customer, also, the developer experience is better than configuring by hand the pieces of the JSON that needs to be assembled, like is happening for `time`.

The pull request is not yet ready to be merged, as I wanted to have an early review of the approach and see if you like it.
If so, what I think should still be done is:
- add a serializer also for timestamps
- add a serializer also for the message
- remove the multitude of options for customizing levels/timestamps/message, as the serializer would be the only way for changing these values
- provide more prepackaged serializers in `pino-std-serializers`

Following, some benchmarks:
```
=== basic.bench.js ===
# next branch
benchPino*10000: 194.908ms
benchPinoExtreme*10000: 72.674ms

# this pr
benchPino*10000: 188.696ms
benchPinoExtreme*10000: 71.806ms

=== child.bench.js ===
# next branch
benchPinoChild*10000: 217.076ms
benchPinoExtremeChild*10000: 80.304ms

# this pr
benchPinoChild*10000: 212.370ms
benchPinoExtremeChild*10000: 88.715ms
```
If this work will get accepted I want to do a follow up where users can configure the order of the keys of the JSON, it shouldn't be a problem to support it and I don't see it introducing too much overhead.

davidmarkclements: great job - I think this is a best-effort solution given all constraints.

We need benchmarks for these new serializers (on vs off) 

Rather than loading from lib symbols, we should use Symbol.for symbols, as we do https://github.com/pinojs/pino/blob/master/lib/symbols.js#L33-L35

So on the same naming scheme as we have currently it would be:

```js
const pino = require('pino')({
  serializers: {
    [Symbol.for('pino.bindings')] (bindings) {
      return {
        process: { pid: bindings.pid },
        hostname: bindings.hostname
      }
    },
    [Symbol.for('pino.level')] (label, number) {
      return {
        log: { level: label }
      }
    }
  }
})
```




delvedor: > How is the bindings serializer called for the child logger? 

It is called when you create a child with the new bindings, the parent's bindings are already part of the instance, and they will not be passed to the serializer.
There is a small "issue" about this tho, I need to override the bindings serializer every time a child is created, otherwise, the new bindings will not be part of the log, because the parent's serializer is still being used.
If the user is not overriding it, I need to do it by hand with the `bindings => bindings`.
Now, when I override the bindings serializer for the child, also the parent gets updated (unless the user has provided their own implementation), it should not be a problem because the bindings serializer is called only once per instance synchronously on creation.

> Is it call for only the new parts added by the child logger?

Yes, see above.

> Is this enough to implement the elastic format?

Yes and no, I still need to work on the time and message serializer, and finally, a key order would be great.

> Can you please refactor the tests so all the cases for the old options are covered anyway?

Done.
delvedor: I've updated the code and introduced the `formatters` top-level options, let me know what you think!
I'll add more tests soon and start working on message and time formatters as well.
davidmarkclements: API looking good, still need equiv for `Symbol.for('pino.*')` 

Only thing now is to make sure it's fast, esp child logger init times
delvedor: Not sure why the test are failing... it works on my machine™!
I'll fix them tomorrow, please still take a look :)
jsumners: @delvedor pull in upstream changes from `next` and rebase. Your errors seem to be related to a PR merged yesterday.
jsumners: This is the test that is failing -- https://github.com/delvedor/pino/blob/9b336b9a2e3b21c824c65d2e286c56faf0d790dd/test/levels.test.js#L431-L444

I cannot pull down your branch and step through it until tonight at the earliest.
jsumners: The issue is that on `levels.test.js:443` the value of `expected.msg` is `null` but the `result` object does not have a `msg` property at all. Which is to say, the serializer is regressing the work done in #711.
delvedor: There are a couple of tests that I don't know how to cover:
```js
function genLsCache (instance) {
  const formatter = instance[formattersSym].level
  const { labels } = instance.levels
  const cache = {}
  for (const label in labels) {
    if (!labels.hasOwnProperty(label)) continue // this line is not covered
    ....
```
```js
function asChindings (instance, bindings) {
  if (!bindings) { // this line is not covered
    throw Error('missing bindings for child Pino')
  }
```

Any suggestion?
delvedor: Given the scope of this pr, I'm not sure it made sense to backport https://github.com/pinojs/pino/pull/772 to `next`, now in my local branch, I have tons of conflicts for a feature that would have been deprecated in any case.
jsumners: The deprecation will be for the duration of the v6 release. So it needed to be kept. 

I did the master to next merge because I expected difficulty syncing this PR with master. 
jsumners: The `hasOwnProperty` test... if you cannot get prototype chain properties into the test then we don’t need the own check. 
davidmarkclements: > The `hasOwnProperty` test... if you cannot get prototype chain properties into the test then we don’t need the own check.

this is hands down the best thing about writing tests, knowing for sure that you can remove code
delvedor: Hello! I've finished the merge and fixed all the conflicts, please take a look, since I had to rewrite a significant part of the code.
jsumners: ping: @delvedor 
jsumners: @delvedor please pull in the latest `next` branch. It adds a GH Action to run benchmarks. See #786 
delvedor: I've addressed all the comments, I'll work on the benchmarks soon.
Regarding line 138 of `lib/tools.js`,I'm not sure how can cover that line, nor how the coverage was present before. Maybe with this pr that path no longer exists?
delvedor: I've added a benchmark for the formatters, please take a look if it is was you were expecting.
mcollina: Also, there seems to be a drop in coverage.
delvedor: I'll work on the docs :)

This is the log of the benchmarks with and without the formatters:
```
benchPinoNoFormatters*10000: 227.418ms
benchPinoFormatters*10000: 260.588ms
benchPinoNoFormatters*10000: 246.946ms
benchPinoFormatters*10000: 252.969ms
```
delvedor: I've updated the documentation, I'm fairly sure that there is still work to do, please give it a look and provide feedback on how you would like to phrase this.
delvedor: Hey folks, I've created a https://github.com/elastic/ecs-logging-js/pull/11 for adding the support of [ecs](https://www.elastic.co/guide/en/ecs/current/index.html) to Pino by using this new feature, everything looks fine! 🎉 
mcollina: Can you amend the title and description of this PR to name "formatters"? Thanks
delvedor: @mcollina I've updated the title, I'll keep the description as is, otherwise, all the discussion below will lose sense. What do you think?
mcollina: ok for me, thanks!
jsumners: @delvedor if you can just resolve the current conflict then we can get this merged and publish an RC. It's an easy resolution but I don't understand the GitHub UI for doing it.
mcollina: > @delvedor if you can just resolve the current conflict then we can get this merged and publish an RC. It's an easy resolution but I don't understand the GitHub UI for doing it.

I've done it.

Patch:
diff --git a/benchmarks/formatters.bench.js b/benchmarks/formatters.bench.js
new file mode 100644
index 0000000..e6cc861
--- /dev/null
+++ 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
index d9660ac..4503ba8 100644
--- 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
index a5fe927..5264bd1 100644
--- 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
index 0f60f7b..81e6631 100644
--- 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
index db44af2..3422710 100644
--- 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
index 13d3662..1480ce7 100644
--- 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
 }
diff --git a/lib/tools.js b/lib/tools.js
index 719b7a9..02772f5 100644
--- a/lib/tools.js
+++ b/lib/tools.js
@@ -18,10 +18,11 @@ const {
   stringifySym,
   wildcardFirstSym,
   needsMetadataGsym,
-  wildcardGsym,
   redactFmtSym,
   streamSym,
-  nestedKeySym
+  nestedKeySym,
+  formattersSym,
+  messageKeySym
 } = require('./symbols')
 
 function noop () {}
@@ -75,12 +76,14 @@ function asString (str) {
   return point < 32 ? JSON.stringify(str) : '"' + result + '"'
 }
 
-function asJson (obj, num, time) {
+function asJson (obj, msg, num, time) {
   const stringify = this[stringifySym]
   const stringifiers = this[stringifiersSym]
   const end = this[endSym]
   const chindings = this[chindingsSym]
   const serializers = this[serializersSym]
+  const formatters = this[formattersSym]
+  const messageKey = this[messageKeySym]
   var data = this[lsCacheSym][num] + time
 
   // we need the child bindings added to the output first so instance logged
@@ -89,8 +92,11 @@ function asJson (obj, num, time) {
 
   var value
   var notHasOwnProperty = obj.hasOwnProperty === undefined
-  if (serializers[wildcardGsym]) {
-    obj = serializers[wildcardGsym](obj)
+  if (formatters.log) {
+    obj = formatters.log(obj)
+  }
+  if (msg !== undefined) {
+    obj[messageKey] = msg
   }
   const wildcardStringifier = stringifiers[wildcardFirstSym]
   for (var key in obj) {
@@ -128,22 +134,20 @@ function asJson (obj, num, time) {
 }
 
 function asChindings (instance, bindings) {
-  if (!bindings) {
-    throw Error('missing bindings for child Pino')
-  }
   var key
   var value
   var data = instance[chindingsSym]
   const stringify = instance[stringifySym]
   const stringifiers = instance[stringifiersSym]
   const serializers = instance[serializersSym]
-  if (serializers[wildcardGsym]) {
-    bindings = serializers[wildcardGsym](bindings)
-  }
+  const formatter = instance[formattersSym].bindings
+  bindings = formatter(bindings)
+
   for (key in bindings) {
     value = bindings[key]
     const valid = key !== 'level' &&
       key !== 'serializers' &&
+      key !== 'formatters' &&
       key !== 'customLevels' &&
       bindings.hasOwnProperty(key) &&
       value !== undefined
@@ -368,6 +372,14 @@ function stringify (obj) {
   }
 }
 
+function buildFormatters (level, bindings, log) {
+  return {
+    level,
+    bindings,
+    log
+  }
+}
+
 function setMetadataProps (dest, that) {
   if (dest[needsMetadataGsym] === true) {
     dest.lastLevel = that.lastLevel
@@ -387,5 +399,6 @@ module.exports = {
   genLog,
   createArgsNormalizer,
   final,
-  stringify
+  stringify,
+  buildFormatters
 }
diff --git a/package.json b/package.json
index 4886ed7..ea1ac22 100644
--- a/package.json
+++ b/package.json
@@ -29,6 +29,7 @@
     "bench-child": "node benchmarks/utils/runbench child",
     "bench-child-child": "node benchmarks/utils/runbench child-child",
     "bench-child-creation": "node benchmarks/utils/runbench child-creation",
+    "bench-formatters": "node benchmarks/utils/runbench formatters",
     "update-bench-doc": "node benchmarks/utils/generate-benchmark-doc > docs/benchmarks.md"
   },
   "bin": {
diff --git a/pino.js b/pino.js
index 4c9dff8..1f03864 100644
--- a/pino.js
+++ b/pino.js
@@ -1,4 +1,5 @@
 'use strict'
+/* eslint no-prototype-builtins: 0 */
 const os = require('os')
 const stdSerializers = require('pino-std-serializers')
 const redaction = require('./lib/redaction')
@@ -11,7 +12,8 @@ const {
   asChindings,
   final,
   stringify,
-  buildSafeSonicBoom
+  buildSafeSonicBoom,
+  buildFormatters
 } = require('./lib/tools')
 const { version } = require('./lib/meta')
 const {
@@ -28,10 +30,9 @@ const {
   formatOptsSym,
   messageKeySym,
   nestedKeySym,
-  useLevelLabelsSym,
-  levelKeySym,
   mixinSym,
-  useOnlyCustomLevelsSym
+  useOnlyCustomLevelsSym,
+  formattersSym
 } = symbols
 const { epochTime, nullTime } = time
 const { pid } = process
@@ -39,7 +40,6 @@ const hostname = os.hostname()
 const defaultErrorSerializer = stdSerializers.err
 const defaultOptions = {
   level: 'info',
-  useLevelLabels: false,
   messageKey: 'msg',
   nestedKey: null,
   enabled: true,
@@ -48,11 +48,19 @@ const defaultOptions = {
   serializers: Object.assign(Object.create(null), {
     err: defaultErrorSerializer
   }),
+  formatters: Object.assign(Object.create(null), {
+    bindings (bindings) {
+      return bindings
+    },
+    level (label, number) {
+      return { level: number }
+    }
+  }),
   timestamp: epochTime,
   name: undefined,
   redact: null,
   customLevels: null,
-  levelKey: 'level',
+  levelKey: undefined,
   useOnlyCustomLevels: false
 }
 
@@ -75,11 +83,43 @@ function pino (...args) {
     level,
     customLevels,
     useLevelLabels,
+    changeLevelName,
     levelKey,
     mixin,
-    useOnlyCustomLevels
+    useOnlyCustomLevels,
+    formatters
   } = opts
 
+  const allFormatters = buildFormatters(
+    formatters.level,
+    formatters.bindings,
+    formatters.log
+  )
+
+  if (useLevelLabels && !(changeLevelName || levelKey)) {
+    process.emitWarning('useLevelLabels is deprecated, use the formatters.level option instead', 'Warning', 'PINODEP001')
+    allFormatters.level = labelsFormatter
+  } else if ((changeLevelName || levelKey) && !useLevelLabels) {
+    process.emitWarning('changeLevelName and levelKey are deprecated, use the formatters.level option instead', 'Warning', 'PINODEP002')
+    allFormatters.level = levelNameFormatter(changeLevelName || levelKey)
+  } else if ((changeLevelName || levelKey) && useLevelLabels) {
+    process.emitWarning('useLevelLabels is deprecated, use the formatters.level option instead', 'Warning', 'PINODEP001')
+    process.emitWarning('changeLevelName and levelKey are deprecated, use the formatters.level option instead', 'Warning', 'PINODEP002')
+    allFormatters.level = levelNameLabelFormatter(changeLevelName || levelKey)
+  }
+
+  if (serializers[Symbol.for('pino.*')]) {
+    process.emitWarning('The pino.* serializer is deprecated, use the formatters.log options instead', 'Warning', 'PINODEP003')
+    allFormatters.log = serializers[Symbol.for('pino.*')]
+  }
+
+  if (!allFormatters.bindings) {
+    allFormatters.bindings = defaultOptions.formatters.bindings
+  }
+  if (!allFormatters.level) {
+    allFormatters.level = defaultOptions.formatters.level
+  }
+
   const stringifiers = redact ? redaction(redact, stringify) : {}
   const formatOpts = redact
     ? { stringify: stringifiers[redactFmtSym] }
@@ -89,7 +129,8 @@ function pino (...args) {
     [chindingsSym]: '',
     [serializersSym]: serializers,
     [stringifiersSym]: stringifiers,
-    [stringifySym]: stringify
+    [stringifySym]: stringify,
+    [formattersSym]: allFormatters
   })
   const chindings = base === null ? '' : (name === undefined)
     ? coreChindings(base) : coreChindings(Object.assign({}, base, { name }))
@@ -105,8 +146,6 @@ function pino (...args) {
 
   Object.assign(instance, {
     levels,
-    [useLevelLabelsSym]: useLevelLabels,
-    [levelKeySym]: levelKey,
     [useOnlyCustomLevelsSym]: useOnlyCustomLevels,
     [streamSym]: stream,
     [timeSym]: time,
@@ -119,17 +158,34 @@ function pino (...args) {
     [nestedKeySym]: nestedKey,
     [serializersSym]: serializers,
     [mixinSym]: mixin,
-    [chindingsSym]: chindings
+    [chindingsSym]: chindings,
+    [formattersSym]: allFormatters
   })
   Object.setPrototypeOf(instance, proto)
 
-  if (customLevels || useLevelLabels || levelKey !== defaultOptions.levelKey) genLsCache(instance)
+  genLsCache(instance)
 
   instance[setLevelSym](level)
 
   return instance
 }
 
+function labelsFormatter (label, number) {
+  return { level: label }
+}
+
+function levelNameFormatter (name) {
+  return function (label, number) {
+    return { [name]: number }
+  }
+}
+
+function levelNameLabelFormatter (name) {
+  return function (label, number) {
+    return { [name]: label }
+  }
+}
+
 pino.extreme = (dest = process.stdout.fd) => {
   process.emitWarning(
     'The pino.extreme() option is deprecated and will be removed in v7. Use pino.destination({ sync: false }) instead.',


Test patch:
diff --git a/test/basic.test.js b/test/basic.test.js
index b0a7faf..445091f 100644
--- a/test/basic.test.js
+++ b/test/basic.test.js
@@ -355,12 +355,12 @@ test('set the base to null', async ({ is, same }) => {
   })
 })
 
-test('set the base to null and use a serializer', async ({ is, same }) => {
+test('set the base to null and use a formatter', async ({ is, same }) => {
   const stream = sink()
   const instance = pino({
     base: null,
-    serializers: {
-      [Symbol.for('pino.*')]: (input) => {
+    formatters: {
+      log (input) {
         return Object.assign({}, input, { additionalMessage: 'using pino' })
       }
     }
@@ -376,10 +376,15 @@ test('set the base to null and use a serializer', async ({ is, same }) => {
   })
 })
 
-test('throw if creating child without bindings', async ({ throws }) => {
+test('throw if creating child without bindings', async ({ is, fail }) => {
   const stream = sink()
   const instance = pino(stream)
-  throws(() => instance.child())
+  try {
+    instance.child()
+    fail('it should throw')
+  } catch (err) {
+    is(err.message, 'missing bindings for child Pino')
+  }
 })
 
 test('correctly escapes msg strings with stray double quote at end', async ({ same }) => {
diff --git a/test/custom-levels.test.js b/test/custom-levels.test.js
index ab1afba..f7b024c 100644
--- a/test/custom-levels.test.js
+++ b/test/custom-levels.test.js
@@ -255,14 +255,18 @@ test('does not share custom level state across siblings', async ({ doesNotThrow
   })
 })
 
-test('custom level does not affect levelKey', async ({ is }) => {
+test('custom level does not affect the levels serializer', async ({ is }) => {
   const stream = sink()
   const logger = pino({
     customLevels: {
       foo: 35,
       bar: 45
     },
-    levelKey: 'priority'
+    formatters: {
+      level (label, number) {
+        return { priority: number }
+      }
+    }
   }, stream)
 
   logger.foo('test')
@@ -270,6 +274,28 @@ test('custom level does not affect levelKey', async ({ is }) => {
   is(priority, 35)
 })
 
+test('When useOnlyCustomLevels is set to true, the level formatter should only get custom levels', async ({ is }) => {
+  const stream = sink()
+  const logger = pino({
+    customLevels: {
+      answer: 42
+    },
+    useOnlyCustomLevels: true,
+    level: 42,
+    formatters: {
+      level (label, number) {
+        is(label, 'answer')
+        is(number, 42)
+        return { level: number }
+      }
+    }
+  }, stream)
+
+  logger.answer('test')
+  const { level } = await once(stream, 'data')
+  is(level, 42)
+})
+
 test('custom levels accesible in prettifier function', async ({ plan, same }) => {
   plan(1)
   const logger = pino({
diff --git a/test/deprecations.test.js b/test/deprecations.test.js
new file mode 100644
index 0000000..59c51c2
--- /dev/null
+++ b/test/deprecations.test.js
@@ -0,0 +1,101 @@
+'use strict'
+/* eslint no-prototype-builtins: 0 */
+
+const { test } = require('tap')
+const { sink, once } = require('./helper')
+const pino = require('../')
+
+process.removeAllListeners('warning')
+
+test('useLevelLabels', async ({ match, is }) => {
+  process.on('warning', onWarning)
+  function onWarning (warn) {
+    is(warn.code, 'PINODEP001')
+  }
+
+  const stream = sink()
+  const logger = pino({
+    useLevelLabels: true
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, { level: 'info' })
+  process.removeListener('warning', onWarning)
+})
+
+test('changeLevelName', async ({ match, is }) => {
+  process.on('warning', onWarning)
+  function onWarning (warn) {
+    is(warn.code, 'PINODEP002')
+  }
+
+  const stream = sink()
+  const logger = pino({
+    changeLevelName: 'priority'
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, { priority: 30 })
+  process.removeListener('warning', onWarning)
+})
+
+test('levelKey', async ({ match, is }) => {
+  process.on('warning', onWarning)
+  function onWarning (warn) {
+    is(warn.code, 'PINODEP002')
+  }
+
+  const stream = sink()
+  const logger = pino({
+    levelKey: 'priority'
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, { priority: 30 })
+  process.removeListener('warning', onWarning)
+})
+
+test('useLevelLabels and changeLevelName', async ({ match, is }) => {
+  let count = 0
+  process.on('warning', onWarning)
+  function onWarning (warn) {
+    is(warn.code, count === 0 ? 'PINODEP001' : 'PINODEP002')
+    count += 1
+  }
+
+  const stream = sink()
+  const logger = pino({
+    changeLevelName: 'priority',
+    useLevelLabels: true
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, { priority: 'info' })
+  process.removeListener('warning', onWarning)
+})
+
+test('pino.* serializer', async ({ match, is, pass }) => {
+  process.on('warning', onWarning)
+  function onWarning (warn) {
+    is(warn.code, 'PINODEP003')
+  }
+
+  const stream = sink()
+  const logger = pino({
+    serializers: {
+      [Symbol.for('pino.*')] (log) {
+        pass('called')
+        return log
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, { level: 30 })
+  process.removeListener('warning', onWarning)
+})
diff --git a/test/formatters.test.js b/test/formatters.test.js
new file mode 100644
index 0000000..7e16f0e
--- /dev/null
+++ b/test/formatters.test.js
@@ -0,0 +1,299 @@
+'use strict'
+/* eslint no-prototype-builtins: 0 */
+
+const { hostname } = require('os')
+const { test } = require('tap')
+const { sink, once } = require('./helper')
+const pino = require('../')
+
+test('level formatter', async ({ match }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      level (label, number) {
+        return {
+          log: {
+            level: label
+          }
+        }
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, {
+    log: {
+      level: 'info'
+    }
+  })
+})
+
+test('bindings formatter', async ({ match }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      bindings (bindings) {
+        return {
+          process: {
+            pid: bindings.pid
+          },
+          host: {
+            name: bindings.hostname
+          }
+        }
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  match(await o, {
+    process: {
+      pid: process.pid
+    },
+    host: {
+      name: hostname()
+    }
+  })
+})
+
+test('no bindings formatter', async ({ match, notOk }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      bindings (bindings) {
+        return null
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info('hello world')
+  const log = await o
+  notOk(log.hasOwnProperty('pid'))
+  notOk(log.hasOwnProperty('hostname'))
+  match(log, { msg: 'hello world' })
+})
+
+test('log formatter', async ({ match, is }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      log (obj) {
+        is(obj.hasOwnProperty('msg'), false)
+        return { hello: 'world', ...obj }
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info({ foo: 'bar', nested: { object: true } }, 'hello world')
+  match(await o, {
+    hello: 'world',
+    foo: 'bar',
+    nested: { object: true }
+  })
+})
+
+test('Formatters combined', async ({ match }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      level (label, number) {
+        return {
+          log: {
+            level: label
+          }
+        }
+      },
+      bindings (bindings) {
+        return {
+          process: {
+            pid: bindings.pid
+          },
+          host: {
+            name: bindings.hostname
+          }
+        }
+      },
+      log (obj) {
+        return { hello: 'world', ...obj }
+      }
+    }
+  }, stream)
+
+  const o = once(stream, 'data')
+  logger.info({ foo: 'bar', nested: { object: true } }, 'hello world')
+  match(await o, {
+    log: {
+      level: 'info'
+    },
+    process: {
+      pid: process.pid
+    },
+    host: {
+      name: hostname()
+    },
+    hello: 'world',
+    foo: 'bar',
+    nested: { object: true }
+  })
+})
+
+test('Formatters in child logger', async ({ match }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      level (label, number) {
+        return {
+          log: {
+            level: label
+          }
+        }
+      },
+      bindings (bindings) {
+        return {
+          process: {
+            pid: bindings.pid
+          },
+          host: {
+            name: bindings.hostname
+          }
+        }
+      },
+      log (obj) {
+        return { hello: 'world', ...obj }
+      }
+    }
+  }, stream)
+
+  const child = logger.child({
+    foo: 'bar',
+    nested: { object: true },
+    formatters: {
+      bindings (bindings) {
+        return { ...bindings, faz: 'baz' }
+      }
+    }
+  })
+
+  const o = once(stream, 'data')
+  child.info('hello world')
+  match(await o, {
+    log: {
+      level: 'info'
+    },
+    process: {
+      pid: process.pid
+    },
+    host: {
+      name: hostname()
+    },
+    hello: 'world',
+    foo: 'bar',
+    nested: { object: true },
+    faz: 'baz'
+  })
+})
+
+test('Formatters without bindings in child logger', async ({ match }) => {
+  const stream = sink()
+  const logger = pino({
+    formatters: {
+      level (label, number) {
+        return {
+          log: {
+            level: label
+          }
+        }
+      },
+      bindings (bindings) {
+        return {
+          process: {
+            pid: bindings.pid
+          },
+          host: {
+            name: bindings.hostname
+          }
+        }
+      },
+      log (obj) {
+        return { hello: 'world', ...obj }
+      }
+    }
+  }, stream)
+
+  const child = logger.child({
+    foo: 'bar',
+    nested: { object: true },
+    formatters: {
+      log (obj) {
+        return { other: 'stuff', ...obj }
+      }
+    }
+  })
+
+  const o = once(stream, 'data')
+  child.info('hello world')
+  match(await o, {
+    log: {
+      level: 'info'
+    },
+    process: {
+      pid: process.pid
+    },
+    host: {
+      name: hostname()
+    },
+    foo: 'bar',
+    other: 'stuff',
+    nested: { object: true }
+  })
+})
+
+test('elastic common schema format', async ({ match, type }) => {
+  const stream = sink()
+  const ecs = {
+    formatters: {
+      level (label, number) {
+        return {
+          log: {
+            level: label,
+            logger: 'pino'
+          }
+        }
+      },
+      bindings (bindings) {
+        return {
+          process: {
+            pid: bindings.pid
+          },
+          host: {
+            name: bindings.hostname
+          }
+        }
+      },
+      log (obj) {
+        return { ecs: { version: '1.4.0' }, ...obj }
+      }
+    },
+    messageKey: 'message',
+    timestamp: () => `,"@timestamp":"${new Date(Date.now()).toISOString()}"`
+  }
+
+  const logger = pino({ ...ecs }, stream)
+
+  const o = once(stream, 'data')
+  logger.info({ foo: 'bar' }, 'hello world')
+  const log = await o
+  type(log['@timestamp'], 'string')
+  match(log, {
+    log: { level: 'info', logger: 'pino' },
+    process: { pid: process.pid },
+    host: { name: hostname() },
+    ecs: { version: '1.4.0' },
+    foo: 'bar',
+    message: 'hello world'
+  })
+})
diff --git a/test/levels.test.js b/test/levels.test.js
index 39b694d..9b6b6de 100644
--- a/test/levels.test.js
+++ b/test/levels.test.js
@@ -237,7 +237,13 @@ test('produces labels when told to', async ({ is }) => {
     level: 'info',
     msg: 'hello world'
   }]
-  const instance = pino({ useLevelLabels: true }, sink((result, enc, cb) => {
+  const instance = pino({
+    formatters: {
+      level (label, number) {
+        return { level: label }
+      }
+    }
+  }, sink((result, enc, cb) => {
     const current = expected.shift()
     check(is, result, current.level, current.msg)
     cb()
@@ -275,7 +281,13 @@ test('changes label naming when told to', async ({ is }) => {
     priority: 30,
     msg: 'hello world'
   }]
-  const instance = pino({ levelKey: 'priority' }, sink((result, enc, cb) => {
+  const instance = pino({
+    formatters: {
+      level (label, number) {
+        return { priority: number }
+      }
+    }
+  }, sink((result, enc, cb) => {
     const current = expected.shift()
     is(result.priority, current.priority)
     is(result.msg, current.msg)
@@ -296,7 +308,13 @@ test('children produce labels when told to', async ({ is }) => {
       msg: 'child 2'
     }
   ]
-  const instance = pino({ useLevelLabels: true }, sink((result, enc, cb) => {
+  const instance = pino({
+    formatters: {
+      level (label, number) {
+        return { level: label }
+      }
+    }
+  }, sink((result, enc, cb) => {
     const current = expected.shift()
     check(is, result, current.level, current.msg)
     cb()
@@ -321,7 +339,11 @@ test('produces labels for custom levels', async ({ is }) => {
     }
   ]
   const opts = {
-    useLevelLabels: true,
+    formatters: {
+      level (label, number) {
+        return { level: label }
+      }
+    },
     customLevels: {
       foo: 35
     }
@@ -339,8 +361,11 @@ test('produces labels for custom levels', async ({ is }) => {
 test('setting levelKey does not affect labels when told to', async ({ is }) => {
   const instance = pino(
     {
-      useLevelLabels: true,
-      levelKey: 'priority'
+      formatters: {
+        level (label, number) {
+          return { priority: label }
+        }
+      }
     },
     sink((result, enc, cb) => {
       is(result.priority, 'info')
diff --git a/test/serializers.test.js b/test/serializers.test.js
index 70e8a6a..d2d871c 100644
--- a/test/serializers.test.js
+++ b/test/serializers.test.js
@@ -206,40 +206,3 @@ test('non-overridden serializers are available in the children', async ({ is })
   parent.fatal({ onlyChild: 'test' })
   is((await o4).onlyChild, 'test')
 })
-
-test('Symbol.for(\'pino.*\') serializer', async ({ notSame, is, isNot }) => {
-  const stream = sink()
-  const globalSerializer = {
-    [Symbol.for('pino.*')]: function (obj) {
-      if (obj.lionel === 'richie') {
-        return { hello: 'is', it: 'me', you: 'are', looking: 'for' }
-      }
-      return { lionel: 'richie' }
-    }
-  }
-
-  const logger = pino({ serializers: globalSerializer }, stream)
-
-  const o = once(stream, 'data')
-  logger.info({ hello: 'is', it: 'me', you: 'are', looking: 'for' })
-  is((await o).lionel, 'richie')
-  isNot((await o).hello, 'is')
-  isNot((await o).it, 'me')
-  isNot((await o).you, 'are')
-  isNot((await o).looking, 'for')
-
-  const o2 = once(stream, 'data')
-  logger.info({ lionel: 'richie' })
-  is((await o2).lionel, 'richie')
-  is((await o2).hello, 'is')
-  is((await o2).it, 'me')
-  is((await o2).you, 'are')
-  is((await o2).looking, 'for')
-
-  const o3 = once(stream, 'data')
-  logger.info('message')
-  is((await o3).lionel, 'richie')
-  is('pid' in (await o3), false)
-  is('hostname' in (await o3), false)
-  notSame(await o3, ['pid', 'hostname'])
-})