Repository: pinojs/hapi-pino
Pull request #32 (2017-11-15 12:05:20)

Fix Hapi Event Handling and Documentation
#33 
- fix description of `logEvents` options
- enable obligatory logging of `request.log()`; just the logging of errored requests is optional.
--> backward compatibility with `v1.x.x`

#31 
- fix description of `log` event
- fix description of `request` event


Patch:
diff --git a/README.md b/README.md
index d814ba0..a22e1da 100644
--- a/README.md
+++ b/README.md
@@ -96,7 +96,7 @@ events"](#hapievents) section.
   The instance's `stream` and `serializers` take precedence.
 - `[logEvents]` - Takes an array of strings with the events to log. Default is to
   log all events e.g. `['onPostStart', 'onPostStop', 'response', 'request-error']`.
-  Set to `false/null` to disable all events.
+  Set to `false/null` to disable all events. Even though there is no `request-error` [Hapi Event](#hapievents), the options enables the logging of failed requests.
 - `[mergeHapiLogData]` - When enabled, Hapi-pino will merge the data received
   from Hapi's logging interface (`server.log(tags, data)` or `request.log(tags, data)`)
   into Pino's logged attributes at root level. If data is a string, it will be used as
@@ -134,10 +134,8 @@ server.log(['info'], {hello: 'world'})
 
 * `'onRequest'`, to create a request-specific child logger
 * `'response'`, to log at `'info'` level when a request is completed
-* `'request'`, to log at `'warn'` level when a request errors for
-  `internal` and `accept-encoding` tags
-* `'log'`, to support logging via the Hapi `server.log()` and
-  `request.log()` methods, see `tags` and `allTags` options.
+* `'request'`, to support logging via the Hapi `request.log()` method and to log at `'warn'` level when a request errors or when request received contains an invalid `accept-encoding` header, see `tags` and `allTags` options.
+* `'log'`, to support logging via the Hapi `server.log()` method and to log in case of an internal server event, see `tags` and `allTags` options.
 * `'onPostStart'`, to log when the server is started
 * `'onPostStop'`, to log when the server is stopped
 
diff --git a/index.js b/index.js
index 701214b..f303852 100644
--- a/index.js
+++ b/index.js
@@ -18,7 +18,7 @@ async function register (server, options) {
   options.serializers.err = options.serializers.err || pino.stdSerializers.err
 
   if (options.logEvents === undefined) {
-    options.logEvents = ['onPostStart', 'onPostStop', 'response', 'request']
+    options.logEvents = ['onPostStart', 'onPostStop', 'response', 'request-error']
   }
 
   var logger
@@ -64,18 +64,20 @@ async function register (server, options) {
     logEvent(logger, event)
   })
 
-  // log when a request completes with an error
-  tryAddEvent(server, options, 'on', 'request', function (request, event, tags) {
+  // log via `request.log()` and optionally when an internal `accept-encoding`
+  // error occurs or request completes with an error
+  server.events.on('request', function (request, event, tags) {
     if (event.channel === 'internal' && !tags['accept-encoding']) {
       return
     }
 
     request.logger = request.logger || logger.child({ req: request })
-    if (event.error) {
+
+    if (event.error && isEnabledLogEvent(options, 'request-error')) {
       request.logger.warn({
         err: event.error
       }, 'request error')
-    } else {
+    } else if (event.channel === 'app') {
       logEvent(request.logger, event)
     }
   })
@@ -98,15 +100,19 @@ async function register (server, options) {
     logger.info(server.info, 'server stopped')
   })
 
+  function isEnabledLogEvent (options, name) {
+    return options.logEvents && options.logEvents.indexOf(name) !== -1
+  }
+
   function tryAddEvent (server, options, type, event, cb) {
     var name = typeof event === 'string' ? event : event.name
-    if (options.logEvents && options.logEvents.indexOf(name) !== -1) {
+    if (isEnabledLogEvent(options, name)) {
       if (type === 'on') {
         server.events.on(event, cb)
       } else if (type === 'ext') {
         server.ext(event, cb)
       } else {
-        throw new Error(`unsupporte type ${type}`)
+        throw new Error(`unsupported type ${type}`)
       }
     }
   }


Test patch:
diff --git a/test.js b/test.js
index d53728c..30fa631 100644
--- a/test.js
+++ b/test.js
@@ -558,6 +558,64 @@ experiment('disables log events', () => {
   })
 })
 
+experiment('logging with `request` event listener', () => {
+  test('with enabled `request-error`', async () => {
+    const server = getServer()
+    let done
+    const finish = new Promise(function (resolve, reject) {
+      done = resolve
+    })
+    const stream = sink((data) => {
+      expect(data.err.stack).to.not.be.undefined()
+      expect(data.err.isBoom).to.be.true()
+      expect(data.err.output.statusCode).to.be.equal(500)
+      done()
+    })
+    const logger = require('pino')(stream)
+    const plugin = {
+      plugin: Pino,
+      options: {
+        instance: logger,
+        logEvents: ['request-error']
+      }
+    }
+
+    await server.register(plugin)
+
+    await server.inject({
+      method: 'GET',
+      url: '/error'
+    })
+
+    await finish
+  })
+
+  test('with disabled `request-error`', async () => {
+    const server = getServer()
+    let called = false
+    const stream = sink(() => {
+      called = true
+    })
+
+    const plugin = {
+      plugin: Pino,
+      options: {
+        stream: stream,
+        logEvents: false
+      }
+    }
+
+    await server.register(plugin)
+
+    await server.inject({
+      method: 'GET',
+      url: '/error'
+    })
+
+    expect(called).to.be.false()
+  })
+})
+
 experiment('uses a prior pino instance', () => {
   test('without pre-defined serializers', async () => {
     const server = getServer()