Repository: pinojs/pino
Pull request #454 (2018-07-18 13:59:40)

pino.final
* replaces `onTerminated` so we're not overriding global handlers
* is useful for `pino.destination` and `pino.extreme` so writes are *always* guaranteed on exit
* much easier to explain and document, non-leaky abstraction
* adds the flush method (correctly)
* precludes the need to a flushSync method


Patch:
diff --git a/docs/api.md b/docs/api.md
index 89b182c..bbc1909 100644
--- a/docs/api.md
+++ b/docs/api.md
@@ -21,6 +21,7 @@
 * [Statics](#statics)
   * [pino.destination()](#pino-destination)
   * [pino.extreme()](#pino-extreme)
+  * [pino.final()](#pino-final)
   * [pino.stdSerializers](#pino-stdserializers)
   * [pino.stdTimeFunctions](#pino-stdtimefunctions)
   * [pino.symbols](#pino-symbols)
@@ -157,26 +158,6 @@ Default: `'msg'`
 
 The string key for the 'message' in the JSON object. 
 
-<a id=onterminated></a>
-#### `onTerminated` (Function)
-
-Default: `(evt, err) => err ? process.exit(1) : process.exit(0)`
-
-This function will be invoked during process shutdown when 
-the supplied destination is an instance of [`pino.extreme`](#pino-extreme)
-
-The signature of the function is `onTerminated(eventName, err)`. 
-
-By default, when `pino.extreme` is used, the `onTerminated` function 
-is set to call `process.exit(1)` on error or else `process.exit(0)`. 
-
-If a function is specified it **must** perform only synchronous operations 
-at this point and then exit the process (there are no ticks left for 
-asynchronous activity at this point in the process lifetime).
-
-* See [pino.extreme](#pino-extreme)
-* See [Extreme mode ⇗](/docs/extreme.md)
-
 <a id=prettyPrint></a>
 #### `prettyPrint` (Boolean | Object)
 
@@ -647,6 +628,38 @@ module.
 * See [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom)
 * See [Extreme mode ⇗](/docs/extreme.md)
 
+<a id="pino-final"></a>
+### `pino.final(logger, handler) => Function`
+
+The `pino.final` method supplies an exit listener function that can be 
+supplied to process exit events such as `exit`, `uncaughtException`, 
+`SIGHUP` and so on. 
+
+The exit listener function will call the supplied `handler` function 
+with an error object (or else `null`), a `finalLogger` instance followed
+by any additional arguments the `handler` may be called with. 
+The `finalLogger` is a specialist logger that synchronously flushes 
+on every write. This is important to gaurantee final log writes, 
+both when using `pino.destination` or `pino.extreme` targets. 
+
+Since final log writes cannot be gauranteed with normal Node.js streams, 
+if the `destination` parameter of the `logger` supplied to `pino.final`
+is a Node.js stream `pino.final` will throw. It's highly recommended
+for both performance and safety to use `pino.destination`/`pino.extreme`
+destinations.
+
+```js
+process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
+  finalLogger.error(err, 'uncaughtException')
+  process.exit(1)
+}))
+```
+
+* See [`destination` parameter](#destination)
+* See [Exit logging help](/docs/help.md#exit-logging)
+* See [Extreme mode ⇗](/docs/extreme.md)
+* See [Log loss prevention ⇗](/docs/extreme.md#log-loss-prevention)
+
 <a id="pino-stdserializers"></a>
 ### `pino.stdSerializers` (Object)
 
diff --git a/docs/extreme.md b/docs/extreme.md
index 0cccf6f..8e5ce99 100644
--- a/docs/extreme.md
+++ b/docs/extreme.md
@@ -6,6 +6,8 @@ In Pino's standard mode of operation log messages are directly written to the
 output stream as the messages are generated. Extereme mode works by buffering
 log messages and writing them in larger chunks.
 
+## Caveats
+
 This has a couple of important caveats:
 
 * 4KB of spare RAM will be needed for logging
@@ -14,6 +16,10 @@ This has a couple of important caveats:
 * There is a possibility of the most recently buffered log messages being lost
   (up to 4KB of logs)
   * For instance, a power cut will mean up to 4KB of buffered logs will be lost
+
+So in summary, only use extreme mode when performing an extreme amount of
+logging and it is acceptable to potentially lose the most recent logs.
+
 * Pino will register handlers for the following process events/signals so that
   Pino can flush the extreme mode buffer:
 
@@ -37,36 +43,53 @@ This has a couple of important caveats:
   signals. If there are more handlers registered than just our own, we will
   simply flush the extreme mode buffer.
 
-So in summary, only use extreme mode when performing an extreme amount of
-logging and it is acceptable to potentially lose the most recent logs.
-
 ## Usage
 
-Extreme mode is defined by creating an extreme mode destination with
-`pino.extreme()`.
-
-The following creates an extreme destination to stdout:
+The `pino.extreme()` method will provide an Extreme Mode destination.
 
 ```js
-'use strict'
+const pino = require('pino')
+const dest = pino.extreme() // logs to stdout with no args
+const logger = pino(dest)
+```
 
+<a id='log-loss-prevention'></a>
+## Log loss prevention
+
+The following strategy can be used to minimize log loss:
+
+```js
 const pino = require('pino')
 const dest = pino.extreme() // no arguments
 const logger = pino(dest)
 
+// asynchronously flush every 10 seconds to keep the buffer empty 
+// in periods of low activity
 setInterval(function () {
-  // flush is asynchronous
-  dest.flush()
+  logger.flush()
 }, 10000).unref()
+
+// use pino.final to create a special logger that 
+// guarantees final tick writes 
+const handler = pino.final(logger, (err, finalLogger, evt) => {
+  finalLogger.info(`${evt} caught`)
+  if (err) finalLogger.error(err, 'error caused exit')
+  process.exit(err ? 1 : 0)
+})
+// catch all the ways node might exit
+process.on('beforeExit', () => handler(null, 'beforeExit'))
+process.on('exit', () => handler(null, 'exit'))
+process.on('uncaughtException', (err) => handler(err, 'uncaughtException'))
+process.on('SIGINT', () => handler(null, 'SIGINT'))
+process.on('SIGQUIT', () => handler(null, 'SIGQUIT'))
+process.on('SIGTERM', () => handler(null, 'SIGTERM'))
 ```
 
 An extreme destination is an instance of
 [`SonicBoom`](https://github.com/mcollina/sonic-boom) with `4096`
 buffering.
 
-In case a synchronous flush is needed, `dest.flushSync()` can be called.
-This method might cause some data loss if a write was already in
-progress, so use it only if truly needed.
 
 * See [`pino.extreme` api](/docs/api.md#pino-extreme)
+* See [`pino.final` api](/docs/api.md#pino-final)
 * See [`destination` parameter](/docs/api.md#destination)
diff --git a/docs/help.md b/docs/help.md
index 76c3973..d1f0f4d 100644
--- a/docs/help.md
+++ b/docs/help.md
@@ -1,5 +1,6 @@
 # Help
 
+* [Exit logging](#exit-logging)
 * [Log rotation](#rotate)
 * [Saving to multiple files](#multiple)
 * [Log Filtering](#filter-logs)
@@ -8,6 +9,34 @@
 * [Log levels as labels instead of numbers](#level-string)
 * [Pino with `debug`](#debug)
 
+<a id="exit-logging"></a>
+## Exit logging
+
+When a Node process crashes from uncaught exception, exits due to a signal, 
+or exits of it's own accord we may want to write some final logs – particularly
+in cases of error. 
+
+Writing to a Node.js stream on exit is not necessarily guaranteed, and naively writing
+to an Extreme Mode logger on exit will definitely lead to lost logs. 
+
+To write logs in an exit handler, create the handler with [`pino.final`](/docs/api.md#pino-final):
+
+```js
+process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
+  finalLogger.error(err, 'uncaughtException')
+  process.exit(1)
+}))
+
+process.on('unhandledRejection', pino.final(logger, (err, finalLogger) => {
+  finalLogger.error(err, 'unhandledRejection')
+  process.exit(1)
+}))
+```
+
+The `finalLogger` is a special logger instance that will synchronously and reliably 
+flush every log line. This is important in exit handlers, since no more asynchronous
+activity may be scheduled.
+
 <a id="rotate"></a>
 ## Log rotation
 
diff --git a/docsify/sidebar.md b/docsify/sidebar.md
index d2b0ad8..33d47ae 100644
--- a/docsify/sidebar.md
+++ b/docsify/sidebar.md
@@ -11,6 +11,7 @@
 * [Benchmarks](/docs/benchmarks.md)
 * [Legacy](/docs/legacy.md)
 * [Help](/docs/help.md)
+  * [Exit Logging](/docs/help.md#exit-logging)
   * [Log Rotation](/docs/help.md#rotate)
   * [Multiple Files](/docs/help.md#multiple)
   * [Log Filtering](/docs/help.md#filter-logs)
diff --git a/lib/events.js b/lib/events.js
deleted file mode 100644
index d1f5309..0000000
--- a/lib/events.js
+++ /dev/null
@@ -1,56 +0,0 @@
-'use strict'
-
-const SonicBoom = require('sonic-boom')
-const { onTerminatedSym, streamSym } = require('./symbols')
-function events (instance) {
-  const stream = instance[streamSym]
-
-  if (stream instanceof SonicBoom) {
-    if (stream.fd === -1) {
-      stream.on('ready', register)
-    } else {
-      register()
-    }
-  }
-
-  function register () {
-    const wrap = (name) => theWorldIsBurning.bind({ name })
-
-    const handlers = {
-      beforeExit: wrap('beforeExit'),
-      uncaughtException: wrap('uncaughtException'),
-      SIGHUP: hup,
-      SIGINT: wrap('SIGINT'),
-      SIGQUIT: wrap('SIGQUIT'),
-      SIGTERM: wrap('SIGTERM')
-    }
-
-    process.on('exit', wrap('exit'))
-
-    function hup () {
-      if (process.listenerCount('SIGHUP') === 1) {
-        return theWorldIsBurning.call({name: 'SIGHUP'})
-      }
-      instance.flush()
-    }
-
-    function theWorldIsBurning (err) {
-      if (theWorldIsBurning.called === true) return
-      theWorldIsBurning.called = true
-      stream.flushSync()
-      if (isExtreme()) instance[onTerminatedSym](this.name, err)
-    }
-
-    function isExtreme () {
-      const stream = instance[streamSym]
-      return stream instanceof SonicBoom &&
-        stream.minLength > 0
-    }
-
-    if (isExtreme()) {
-      Object.keys(handlers).forEach((k) => process.on(k, handlers[k]))
-    }
-  }
-}
-
-module.exports = events
diff --git a/lib/proto.js b/lib/proto.js
index ff67245..3ab4b03 100644
--- a/lib/proto.js
+++ b/lib/proto.js
@@ -100,5 +100,5 @@ function write (obj, msg, num) {
 
 function flush () {
   const stream = this[streamSym]
-  if ('flushSync' in stream) stream.flushSync()
+  if ('flush' in stream) stream.flush()
 }
diff --git a/lib/symbols.js b/lib/symbols.js
index e6b78fd..b704c70 100644
--- a/lib/symbols.js
+++ b/lib/symbols.js
@@ -19,7 +19,6 @@ const stringifySym = Symbol('pino.stringify')
 const stringifiersSym = Symbol('pino.stringifiers')
 const endSym = Symbol('pino.end')
 const formatOptsSym = Symbol('pino.formatOpts')
-const onTerminatedSym = Symbol('pino.onTerminated')
 const messageKeyStringSym = Symbol('pino.messageKeyString')
 
 const wildcardGsym = Symbol.for('pino.*')
@@ -42,7 +41,6 @@ module.exports = {
   stringifiersSym,
   endSym,
   formatOptsSym,
-  onTerminatedSym,
   messageKeyStringSym,
   wildcardGsym,
   needsMetadataGsym
diff --git a/lib/tools.js b/lib/tools.js
index ba346de..1efb9fe 100644
--- a/lib/tools.js
+++ b/lib/tools.js
@@ -15,7 +15,8 @@ const {
   stringifiersSym,
   stringifySym,
   needsMetadataGsym,
-  wildcardGsym
+  wildcardGsym,
+  streamSym
 } = require('./symbols')
 
 function noop () {}
@@ -181,7 +182,10 @@ function createArgsNormalizer (defaultOptions) {
     }
     opts = Object.assign({}, defaultOptions, opts)
     if ('extreme' in opts) {
-      throw new Error('The extreme option has been removed, use require(\'pino\').extreme(dest) instead')
+      throw Error('The extreme option has been removed, use pino.extreme instead')
+    }
+    if ('onTerminated' in opts) {
+      throw Error('The onTerminated option has been removed, use pino.final instead')
     }
     const { enabled, prettyPrint, prettifier, messageKey } = opts
     if (enabled === false) opts.level = 'silent'
@@ -197,11 +201,48 @@ function createArgsNormalizer (defaultOptions) {
   }
 }
 
+function final (logger, handler) {
+  if (typeof logger === 'undefined' || typeof logger.child !== 'function') {
+    throw Error('expected a pino logger instance')
+  }
+  if (typeof handler !== 'function') {
+    throw Error('expected a handler function')
+  }
+  const stream = logger[streamSym]
+  if (!(stream instanceof SonicBoom)) {
+    throw Error('only compatible with loggers with pino.destination and pino.extreme targets')
+  }
+
+  return (err = null, ...args) => {
+    try {
+      stream.flushSync()
+    } catch (e) {
+      // it's too late to wait for the stream to be ready
+      // because this is a final tick scenario.
+      // in practice there shouldn't be a situation where it isn't
+      // however, swallow the error just in case (and for easier testing)
+    }
+    const finalLogger = new Proxy(logger, {
+      get: (logger, key) => {
+        if (key in logger.levels.values) {
+          return (...args) => {
+            logger[key](...args)
+            stream.flushSync()
+          }
+        }
+        return logger[key]
+      }
+    })
+    return handler(err, finalLogger, ...args)
+  }
+}
+
 module.exports = {
   noop,
   getPrettyStream,
   asChindings,
   asJson,
   genLog,
-  createArgsNormalizer
+  createArgsNormalizer,
+  final
 }
diff --git a/package.json b/package.json
index f9bac2e..dbe8a24 100644
--- a/package.json
+++ b/package.json
@@ -23,7 +23,7 @@
     "bench": "node benchmarks/utils/runbench all",
     "bench-basic": "node benchmarks/utils/runbench basic",
     "bench-object": "node benchmarks/utils/runbench object",
-    "bench-deepo-bject": "node benchmarks/utils/runbench deep-object",
+    "bench-deep-object": "node benchmarks/utils/runbench deep-object",
     "bench-multi-arg": "node benchmarks/utils/runbench multi-arg",
     "bench-longs-tring": "node benchmarks/utils/runbench long-string",
     "bench-child": "node benchmarks/utils/runbench child",
diff --git a/pino.js b/pino.js
index 2f70eb7..4c5404c 100644
--- a/pino.js
+++ b/pino.js
@@ -3,13 +3,12 @@ const os = require('os')
 const stringifySafe = require('fast-safe-stringify')
 const serializers = require('pino-std-serializers')
 const SonicBoom = require('sonic-boom')
-const events = require('./lib/events')
 const redaction = require('./lib/redaction')
 const time = require('./lib/time')
 const proto = require('./lib/proto')
 const symbols = require('./lib/symbols')
 const { mappings, genLsCache, assertNoLevelCollisions } = require('./lib/levels')
-const { createArgsNormalizer, asChindings } = require('./lib/tools')
+const { createArgsNormalizer, asChindings, final } = require('./lib/tools')
 const { version, LOG_VERSION } = require('./lib/meta')
 const {
   chindingsSym,
@@ -22,11 +21,10 @@ const {
   setLevelSym,
   endSym,
   formatOptsSym,
-  onTerminatedSym,
   messageKeyStringSym
 } = symbols
 const { epochTime, nullTime } = time
-const { pid, exit } = process
+const { pid } = process
 const hostname = os.hostname()
 const defaultErrorSerializer = serializers.err
 const defaultOptions = {
@@ -38,7 +36,6 @@ const defaultOptions = {
   base: { pid, hostname },
   serializers: {err: defaultErrorSerializer},
   timestamp: epochTime,
-  onTerminated: (evt, err) => err ? exit(1) : exit(0),
   name: undefined,
   redact: null,
   customLevels: null
@@ -54,7 +51,6 @@ function pino (...args) {
     crlf,
     serializers,
     timestamp,
-    onTerminated,
     messageKey,
     base,
     name,
@@ -92,7 +88,6 @@ function pino (...args) {
     [stringifiersSym]: stringifiers,
     [endSym]: end,
     [formatOptsSym]: formatOpts,
-    [onTerminatedSym]: onTerminated,
     [messageKeyStringSym]: messageKeyString,
     [serializersSym]: serializers,
     [chindingsSym]: chindings
@@ -101,8 +96,6 @@ function pino (...args) {
 
   if (customLevels) genLsCache(instance)
 
-  events(instance)
-
   instance[setLevelSym](level)
 
   return instance
@@ -110,6 +103,7 @@ function pino (...args) {
 
 pino.extreme = (dest = process.stdout.fd) => new SonicBoom(dest, 4096)
 pino.destination = (dest = process.stdout.fd) => new SonicBoom(dest)
+pino.final = final
 pino.levels = mappings()
 pino.stdSerializers = Object.assign({}, serializers)
 pino.stdTimeFunctions = Object.assign({}, time)


Test patch:
diff --git a/test/events.test.js b/test/events.test.js
deleted file mode 100644
index ab28ac4..0000000
--- a/test/events.test.js
+++ /dev/null
@@ -1,59 +0,0 @@
-'use strict'
-
-const { test } = require('tap')
-const { join } = require('path')
-const { fork, spawn, spawnSync } = require('child_process')
-const { once } = require('./helper')
-
-const fixtures = join(__dirname, 'fixtures', 'events')
-
-test('logs successfully in a single tick process', async ({is}) => {
-  const child = fork(join(fixtures, 'single-tick.js'), {silent: true})
-  const output = await once(child.stdout, 'data')
-  await once(child, 'close')
-  is(/"msg":"h"/.test(await output), true)
-})
-
-test('terminates when uncaughtException is fired with onTerminated registered', async ({is}) => {
-  const { stdout, stderr, status } = spawnSync(process.argv[0], [join(fixtures, 'uncaught-exception.js')], {timeout: 30000})
-  is(status, 0)
-  is(/"msg":"h"/.test(stdout), true)
-  is(/terminated/g.test(stdout), true)
-  is(/this is not caught/g.test(stderr), true)
-})
-
-test('terminates when uncaughtException is fired without onTerminated registered', async ({is}) => {
-  const { stdout, status } = spawnSync(process.argv[0], [join(fixtures, 'uncaught-exception-no-terminate.js')], {timeout: 30000})
-  is(status, 1)
-  is(/"msg":"h"/.test(stdout), true)
-})
-
-test('terminates on SIGHUP when no other handlers registered', async ({is}) => {
-  const child = spawn(process.argv[0], [join(fixtures, 'sighup-no-handler.js')])
-  await once(child.stdout, 'data')
-  const output = once(child.stdout, 'data')
-  child.kill('SIGHUP')
-  const code = await once(child, 'exit')
-  is(code, 0)
-  is(/"msg":"h"/.test(await output), true)
-})
-
-test('lets app terminate when SIGHUP received with multiple handlers', async ({is}) => {
-  const child = spawn(process.argv[0], [join(fixtures, 'sighup-with-handler.js')])
-  await once(child.stdout, 'data')
-  const output = once(child.stdout, 'data')
-  const output2 = output.then(() => once(child.stdout, 'data'))
-  const code = once(child, 'exit')
-  child.kill('SIGHUP')
-  is(await code, 0)
-  is(/"msg":"h"/.test(await output + ''), true)
-  is(/app sighup/.test(await output2 + ''), true)
-})
-
-test('destination', async ({is}) => {
-  const child = spawn(process.argv[0], [join(fixtures, 'destination.js')], {silent: true})
-  const output = once(child.stdout, 'data')
-  const code = await once(child, 'exit')
-  is(code, 0)
-  is(/"msg":"h"/.test(await output), true)
-})
diff --git a/test/final.test.js b/test/final.test.js
new file mode 100644
index 0000000..c1860aa
--- /dev/null
+++ b/test/final.test.js
@@ -0,0 +1,149 @@
+'use strict'
+const pino = require('..')
+const fs = require('fs')
+const { test } = require('tap')
+const { sleep } = require('./helper')
+
+test('replaces onTerminated option', async ({throws}) => {
+  throws(() => {
+    pino({
+      onTerminated: () => {}
+    })
+  }, Error('The onTerminated option has been removed, use pino.final instead'))
+})
+
+test('throws if not supplied a logger instance', async ({throws}) => {
+  throws(() => {
+    pino.final()
+  }, Error('expected a pino logger instance'))
+})
+
+test('throws if not supplied a handler', async ({throws}) => {
+  throws(() => {
+    pino.final(pino())
+  }, Error('expected a handler function'))
+})
+
+test('throws if not supplied logger with pino.destination or pino.extreme instance', async ({throws, doesNotThrow}) => {
+  throws(() => {
+    pino.final(pino(fs.createWriteStream('/dev/null')), () => {})
+  }, Error('only compatible with loggers with pino.destination and pino.extreme'))
+
+  doesNotThrow(() => {
+    pino.final(pino(pino.destination()), () => {})
+  })
+
+  doesNotThrow(() => {
+    pino.final(pino(pino.extreme()), () => {})
+  })
+})
+
+test('returns an exit listener function', async ({is}) => {
+  is(typeof pino.final(pino(pino.destination()), () => {}), 'function')
+})
+
+test('listener function immediately sync flushes when fired', async ({pass, fail}) => {
+  const dest = pino.destination('/dev/null')
+  var passed = false
+  dest.flushSync = () => {
+    passed = true
+    pass('flushSync called')
+  }
+  pino.final(pino(dest), () => {})()
+  await sleep(10)
+  if (passed === false) fail('flushSync not called')
+})
+
+test('swallows the non-ready error', async ({doesNotThrow}) => {
+  const dest = pino.destination('/dev/null')
+  doesNotThrow(() => {
+    pino.final(pino(dest), () => {})()
+  })
+})
+
+test('listener function triggers handler function parameter', async ({pass, fail}) => {
+  const dest = pino.destination('/dev/null')
+  var passed = false
+  pino.final(pino(dest), () => {
+    passed = true
+    pass('handler function triggered')
+  })()
+  await sleep(10)
+  if (passed === false) fail('handler function not triggered')
+})
+
+test('passes any error to the handler', async ({is}) => {
+  const dest = pino.destination('/dev/null')
+  pino.final(pino(dest), (err) => {
+    is(err.message, 'test')
+  })(Error('test'))
+})
+
+test('passes a specialized final logger instance', async ({is, isNot, error}) => {
+  const dest = pino.destination('/dev/null')
+  const logger = pino(dest)
+  pino.final(logger, (err, finalLogger) => {
+    error(err)
+
+    is(typeof finalLogger.trace, 'function')
+    is(typeof finalLogger.debug, 'function')
+    is(typeof finalLogger.info, 'function')
+    is(typeof finalLogger.warn, 'function')
+    is(typeof finalLogger.error, 'function')
+    is(typeof finalLogger.fatal, 'function')
+
+    isNot(finalLogger.trace, logger.trace)
+    isNot(finalLogger.debug, logger.debug)
+    isNot(finalLogger.info, logger.info)
+    isNot(finalLogger.warn, logger.warn)
+    isNot(finalLogger.error, logger.error)
+    isNot(finalLogger.fatal, logger.fatal)
+
+    is(finalLogger.child, logger.child)
+    is(finalLogger.levels, logger.levels)
+  })()
+})
+
+test('final logger instances synchronously flush after a log method call', async ({pass, fail, error}) => {
+  const dest = pino.destination('/dev/null')
+  const logger = pino(dest)
+  var passed = false
+  var count = 0
+  dest.flushSync = () => {
+    count++
+    if (count === 2) {
+      passed = true
+      pass('flushSync called')
+    }
+  }
+  pino.final(logger, (err, finalLogger) => {
+    error(err)
+    finalLogger.info('hello')
+  })()
+  await sleep(10)
+  if (passed === false) fail('flushSync not called')
+})
+
+test('also instruments custom log methods', async ({pass, fail, error}) => {
+  const dest = pino.destination('/dev/null')
+  const logger = pino({
+    customLevels: {
+      foo: 35
+    }
+  }, dest)
+  var passed = false
+  var count = 0
+  dest.flushSync = () => {
+    count++
+    if (count === 2) {
+      passed = true
+      pass('flushSync called')
+    }
+  }
+  pino.final(logger, (err, finalLogger) => {
+    error(err)
+    finalLogger.foo('hello')
+  })()
+  await sleep(10)
+  if (passed === false) fail('flushSync not called')
+})
diff --git a/test/fixtures/events/destination.js b/test/fixtures/events/destination.js
deleted file mode 100644
index 05ffee8..0000000
--- a/test/fixtures/events/destination.js
+++ /dev/null
@@ -1,12 +0,0 @@
-'use strict'
-
-// we need stable data to run our tests
-global.process = { __proto__: process, pid: 123456 }
-Date.now = function () { return 1459875739796 }
-require('os').hostname = function () { return 'abcdefghijklmnopqr' }
-
-var pino = require(require.resolve('./../../../'))
-
-// use a destination
-var log = pino(pino.destination())
-log.info('h')
diff --git a/test/fixtures/events/no-destination.js b/test/fixtures/events/no-destination.js
deleted file mode 100644
index 3302e66..0000000
--- a/test/fixtures/events/no-destination.js
+++ /dev/null
@@ -1,21 +0,0 @@
-'use strict'
-
-// we need stable data to run our tests
-global.process = { __proto__: process, pid: 123456 }
-Date.now = function () { return 1459875739796 }
-require('os').hostname = function () { return 'abcdefghijklmnopqr' }
-
-if (process.listenerCount('SIGHUP') > 0) {
-  // needed because of a hook added by code coverage
-  process.removeAllListeners('SIGHUP')
-}
-
-var pino = require(require.resolve('./../../../'))
-
-var log = pino()
-log.info('h')
-
-function foo () {
-  setTimeout(foo, 500)
-}
-foo()
diff --git a/test/fixtures/events/sighup-no-handler.js b/test/fixtures/events/sighup-no-handler.js
deleted file mode 100644
index e596abc..0000000
--- a/test/fixtures/events/sighup-no-handler.js
+++ /dev/null
@@ -1,23 +0,0 @@
-'use strict'
-
-// we need stable data to run our tests
-global.process = { __proto__: process, pid: 123456 }
-Date.now = function () { return 1459875739796 }
-require('os').hostname = function () { return 'abcdefghijklmnopqr' }
-
-if (process.listenerCount('SIGHUP') > 0) {
-  // needed because of a hook added by code coverage
-  process.removeAllListeners('SIGHUP')
-}
-
-var pino = require(require.resolve('./../../../'))
-
-// extreme mode
-var log = pino(pino.extreme())
-log.info('h')
-
-function foo () {
-  setTimeout(foo, 500)
-}
-console.log('ready')
-foo()
diff --git a/test/fixtures/events/sighup-with-handler.js b/test/fixtures/events/sighup-with-handler.js
deleted file mode 100644
index c564b5b..0000000
--- a/test/fixtures/events/sighup-with-handler.js
+++ /dev/null
@@ -1,17 +0,0 @@
-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(pino.extreme())
-log.info('h')
-
-process.on('SIGHUP', function () {
-  console.log('app sighup')
-  process.exit(0)
-})
-
-function foo () {
-  setTimeout(foo, 500)
-}
-console.log('ready')
-foo()
diff --git a/test/fixtures/events/single-tick.js b/test/fixtures/events/single-tick.js
deleted file mode 100644
index 6c70c55..0000000
--- a/test/fixtures/events/single-tick.js
+++ /dev/null
@@ -1,6 +0,0 @@
-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(pino.extreme())
-log.info('h')
diff --git a/test/fixtures/events/uncaught-exception-no-terminate.js b/test/fixtures/events/uncaught-exception-no-terminate.js
deleted file mode 100644
index 9271710..0000000
--- a/test/fixtures/events/uncaught-exception-no-terminate.js
+++ /dev/null
@@ -1,8 +0,0 @@
-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(pino.extreme())
-log.info('h')
-
-setTimeout(function () { throw Error('this is not caught') }, 500)
diff --git a/test/fixtures/events/uncaught-exception.js b/test/fixtures/events/uncaught-exception.js
deleted file mode 100644
index 5006185..0000000
--- a/test/fixtures/events/uncaught-exception.js
+++ /dev/null
@@ -1,14 +0,0 @@
-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({
-  onTerminated: function (evt, err) {
-    console.error(err.message)
-    console.log('terminated')
-    process.exit()
-  }
-}, pino.extreme())
-log.info('h')
-
-setTimeout(function () { throw Error('this is not caught') }, 500)
diff --git a/test/fixtures/extreme-child.js b/test/fixtures/extreme-child.js
index e6ec270..81528ab 100644
--- a/test/fixtures/extreme-child.js
+++ b/test/fixtures/extreme-child.js
@@ -3,4 +3,4 @@ Date.now = function () { return 1459875739796 }
 require('os').hostname = function () { return 'abcdefghijklmnopqr' }
 var pino = require(require.resolve('./../../'))
 var extreme = pino(pino.extreme()).child({ hello: 'world' })
-extreme.info('h')
+pino.final(extreme, (_, logger) => logger.info('h'))()
diff --git a/test/fixtures/extreme.js b/test/fixtures/extreme.js
index 50d08dd..20b2a6c 100644
--- a/test/fixtures/extreme.js
+++ b/test/fixtures/extreme.js
@@ -3,4 +3,4 @@ Date.now = function () { return 1459875739796 }
 require('os').hostname = function () { return 'abcdefghijklmnopqr' }
 var pino = require(require.resolve('./../../'))
 var extreme = pino(pino.extreme())
-extreme.info('h')
+pino.final(extreme, (_, logger) => logger.info('h'))()
diff --git a/test/helper.js b/test/helper.js
index b6b322e..a46ff6e 100644
--- a/test/helper.js
+++ b/test/helper.js
@@ -33,4 +33,10 @@ function check (is, chunk, level, msg) {
   is(chunk.v, v)
 }
 
-module.exports = { sink, check, once }
+function sleep (ms) {
+  return new Promise((resolve) => {
+    setTimeout(resolve, ms)
+  })
+}
+
+module.exports = { sink, check, once, sleep }