hapi-pino - npm Package Compare versions

Comparing version 9.1.2 to 9.2.0

index.js

@@ -40,3 +40,3 @@ 'use strict'
 
-  var logger
+  let logger
   if (options.instance) {
@@ -55,3 +55,3 @@ logger = options.instance
     options.stream = options.stream || process.stdout
-    var stream = options.stream || process.stdout
+    const stream = options.stream || process.stdout
     logger = pino(options, stream)
@@ -74,3 +74,3 @@ }
 
-  var ignoreTable = {}
+  const ignoreTable = {}
   if (options.ignorePaths) {
@@ -115,3 +115,3 @@ for (let i = 0; i < options.ignorePaths.length; i++) {
       request.logger.info({
-        req: request
+        req: childBindings.req ? undefined : request
       }, 'request start')
@@ -173,2 +173,5 @@ }
       }
+
+      // If you want `req` to be added either use the default `getChildBindings` or make sure `req` is passed in your custom bindings.
+      const responseTime = (info.completed !== undefined ? info.completed : info.responded) - info.received
       request.logger.info(
@@ -179,9 +182,6 @@ {
           tags: options.logRouteTags ? request.route.settings.tags : undefined,
-          // note: pino doesnt support unsetting a key, so this next line
-          // has the effect of setting it or "leaving it as it was" if it was already added via child bindings
-          req: shouldLogRequestStart(request) ? undefined : request,
           res: request.raw.res,
-          responseTime: (info.completed !== undefined ? info.completed : info.responded) - info.received
+          responseTime
         },
-        'request completed'
+        `[response] ${request.method} ${request.path} ${request.raw.res.statusCode} (${responseTime}ms)`
       )
@@ -224,3 +224,3 @@ }
 
-    for (var index = ignoreTags.length; index >= 0; index--) {
+    for (let index = ignoreTags.length; index >= 0; index--) {
       if (routeTags.includes(ignoreTags[index])) {
@@ -239,3 +239,3 @@ return true
   function tryAddEvent (server, options, type, event, cb) {
-    var name = typeof event === 'string' ? event : event.name
+    const name = typeof event === 'string' ? event : event.name
     if (isEnabledLogEvent(options, name)) {
@@ -258,8 +258,8 @@ if (type === 'on') {
 
-    var tags = event.tags
-    var data = event.data
+    const tags = event.tags
+    let data = event.data
 
-    var logObject
+    let logObject
     if (mergeHapiLogData) {
-      if (typeof data === 'string') {
+      if (typeof data === 'string' || typeof data === 'number') {
         data = { [messageKey]: data }
@@ -266,0 +266,0 @@ }

package.json

 {
   "name": "hapi-pino",
-  "version": "9.1.2",
+  "version": "9.2.0",
   "description": "Hapi plugin for the Pino logger ",
@@ -23,20 +23,20 @@ "main": "index.js",
   "devDependencies": {
-    "@hapi/code": "^8.0.0",
+    "@hapi/code": "^8.0.7",
     "@hapi/hapi": "^20.2.1",
-    "@hapi/lab": "^24.3.2",
-    "coveralls": "^3.0.11",
+    "@hapi/lab": "^24.5.1",
+    "coveralls": "^3.1.1",
     "flush-write-stream": "^2.0.0",
     "make-promises-safe": "^5.1.0",
-    "pino-pretty": "^7.2.0",
+    "pino-pretty": "^7.5.3",
     "pre-commit": "^1.2.2",
-    "split2": "^3.1.1",
-    "standard": "^14.3.3",
-    "tsd": "^0.18.0"
+    "split2": "^4.1.0",
+    "standard": "^16.0.4",
+    "tsd": "^0.19.1"
   },
   "dependencies": {
-    "@hapi/hoek": "^9.0.0",
-    "@types/hapi__hapi": "^20.0.9",
-    "abstract-logging": "^2.0.0",
+    "@hapi/hoek": "^9.2.1",
+    "@types/hapi__hapi": "^20.0.10",
+    "abstract-logging": "^2.0.1",
     "get-caller-file": "^2.0.5",
-    "pino": "^7.0.0"
+    "pino": "^7.8.1"
   },
@@ -43,0 +43,0 @@ "repository": {

README.md

@@ -119,3 +119,3 @@ # hapi-pino  ![Tests Status](https://github.com/pinojs/hapi-pino/actions/workflows/test.yml/badge.svg) [![Coverage Status](https://coveralls.io/repos/github/pinojs/hapi-pino/badge.svg?branch=master)](https://coveralls.io/github/pinojs/hapi-pino?branch=master)
   Note: when `logRequestStart` is enabled and `getChildBindings` is configured to omit the `req` field, then the `req` field will be
-  omitted from the `request completed` log event. This behavior is useful if you want to separate requests from responses and link the
+  omitted from the `request completed` log event but the `req` field will always be there for the start log. This behavior is useful if you want to separate requests from responses and link the
   two via requestId (frequently done via `headers['x-request-id']`) , where "request start" only logs the request and a requestId,
@@ -163,3 +163,4 @@ and `request completed` only logs the response and the requestId.
  To redact the authorization header in the logs:
-  ```
+
+  ```js
   {
@@ -211,2 +212,4 @@ req: require('pino-noir')(['req.headers.authorization']).req
 
+  Note: Omitting `req` from the child bindings will omit it from all logs, most notably the response log, except "request start".
+
 ### `options.ignorePaths: string[]`
@@ -253,3 +256,3 @@ Takes an array of string routes and disables logging for each.  Useful for health checks or any route that does not need logging.
 
-  **Example**: 
+  **Example**:
   Do not log the events for DEBUG and TEST tag
@@ -265,3 +268,3 @@ ```js
 
-  Set the minumum level that Pino should log out. See [Level](https://github.com/pinojs/pino/blob/master/docs/api.md#level).
+  Set the minimum level that Pino should log out. See [Level](https://github.com/pinojs/pino/blob/master/docs/api.md#level).
 
@@ -289,3 +292,3 @@ **Example**:
 
-* `request.logger`, which is an instance of [pino][pino] bound to the current request, so you can trace all the logs of a given request. See [pino][pino] doc for the way to actual log.
+- `request.logger`, which is an instance of [pino][pino] bound to the current request, so you can trace all the logs of a given request. See [pino][pino] doc for the way to actual log.
 
@@ -297,8 +300,8 @@ <a name="hapievents"></a>
 
-* `'onRequest'`, to create a request-specific child logger
-* `'response'`, to log at `'info'` level when a request is completed
-* `'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
+- `'onRequest'`, to create a request-specific child logger
+- `'response'`, to log at `'info'` level when a request is completed
+- `'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
 
@@ -305,0 +308,0 @@ ## Acknowledgements

test.js

@@ -52,3 +52,3 @@ 'use strict'
 function sink (func) {
-  var result = split(JSON.parse)
+  const result = split(JSON.parse)
   result.pipe(writeStream.obj(func))
@@ -159,3 +159,3 @@ return result
       expect(data.res.statusCode).to.equal(200)
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/get \/something 200 \(\d*ms\)/)
       expect(data.responseTime).to.be.at.least(0)
@@ -170,2 +170,32 @@ done()
 
+  test('without duplicate req data', async () => {
+    const server = getServer()
+    let done
+
+    const finish = new Promise(function (resolve, reject) {
+      done = resolve
+    })
+
+    // We do a manual setup here compared to other tests
+    // as the `JSON.parse` in the `sink` function hides the double key from us.
+    const stream = split()
+    stream.pipe(writeStream.obj((data) => {
+      expect(data.match(/"req":/g).length).to.equal(1)
+
+      done()
+    }))
+
+    const plugin = {
+      plugin: Pino,
+      options: {
+        stream: stream,
+        level: 'info'
+      }
+    }
+
+    await server.register(plugin)
+    await server.inject('/something')
+    await finish
+  })
+
   test('track responseTime', async () => {
@@ -191,3 +221,3 @@ const server = getServer()
       expect(data.res.statusCode).to.equal(200)
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/ 200 \(\d*ms\)/)
       expect(data.responseTime).to.be.at.least(10)
@@ -221,3 +251,3 @@ done()
       expect(data.res.statusCode).to.equal(200)
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/ 200 \(\d*ms\)/)
       expect(data.responseTime)
@@ -255,3 +285,3 @@ .to.be.a.number()
       expect(data.res.statusCode).to.equal(200)
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/ 200 \(\d*ms\)/)
       cb()
@@ -286,3 +316,3 @@ done()
         expect(data.level).to.equal(30)
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/get \/ 500 \(\d*ms\)/)
         done()
@@ -339,3 +369,3 @@ }
         expect(data.res.statusCode).to.equal(200)
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/get \/ 200 \(\d*ms\)/)
         done()
@@ -397,3 +427,3 @@ }
       expect(data.res.statusCode).to.equal(200)
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/ 200 \(\d*ms\)/)
       done()
@@ -596,2 +626,3 @@ })
           expect(data.data).to.equal('hello logger')
+          expect(data.req).to.not.be.undefined()
           resolver()
@@ -920,3 +951,3 @@ }
     const stream = sink(data => {
-      expect(data.req).to.not.be.undefined()
+      expect(data.req).to.be.undefined()
       expect(data.custom).to.not.be.undefined()
@@ -949,3 +980,3 @@ done()
     const stream = sink(data => {
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
       expect(data.req).to.be.an.object()
@@ -977,3 +1008,3 @@ expect(data.req.id).to.exists()
     const stream = sink(data => {
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
       expect(data.req).to.be.an.object()
@@ -1049,3 +1080,3 @@ expect(data.req.id).to.exists()
         expect(data.req.url).to.endWith('/ignored')
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/\[response\] get \/ignored 200 \(\d*ms\)/)
       } else if (count === 1) {
@@ -1056,3 +1087,3 @@ expect(data.req.url).to.endWith('/foo')
         expect(data.req.url).to.endWith('/foo')
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/\[response\] get \/foo 200 \(\d*ms\)/)
         done()
@@ -1101,3 +1132,3 @@ }
       } else {
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
         expect(data.req).to.be.an.object()
@@ -1138,3 +1169,3 @@ expect(data.res).to.be.an.object()
       } else {
-        expect(data.msg).to.equal('request completed')
+        expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
         expect(data.req).to.be.undefined()
@@ -1162,2 +1193,38 @@ expect(data.res).to.be.an.object()
   })
+
+  test('when options.logRequestStart is true, don\'t log req twice ', async () => {
+    const server = getServer()
+    let done
+
+    const finish = new Promise(function (resolve, reject) {
+      done = resolve
+    })
+
+    // We do a manual setup here compared to other tests
+    // as the `JSON.parse` in the `sink` function hides the double key from us.
+    const stream = split()
+    stream.pipe(writeStream.obj((data, enc, cb) => {
+      expect(data.match(/"req":/g).length).to.equal(1)
+
+      // If we get to the response log we're done
+      if (data.includes('"responseTime":')) {
+        done()
+      }
+
+      cb()
+    }))
+
+    const plugin = {
+      plugin: Pino,
+      options: {
+        stream: stream,
+        level: 'info',
+        logRequestStart: true
+      }
+    }
+
+    await server.register(plugin)
+    await server.inject('/something')
+    await finish
+  })
 })
@@ -1174,3 +1241,3 @@
     const stream = sink(data => {
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
       expect(data.req).to.be.an.object()
@@ -1202,3 +1269,3 @@ expect(data.req.id).to.exists()
     const stream = sink(data => {
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/something 200 \(\d*ms\)/)
       expect(data.req).to.be.an.object()
@@ -1281,3 +1348,3 @@ expect(data.req.id).to.exists()
       expect(data.req.url).to.endWith('/foo')
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] get \/foo 200 \(\d*ms\)/)
       done()
@@ -1360,2 +1427,26 @@ })
 
+  test('when data is a number, merge it as msg property', async () => {
+    const server = getServer()
+    let done
+    const finish = new Promise(function (resolve, reject) {
+      done = resolve
+    })
+    const stream = sink(data => {
+      expect(data).to.include({ msg: 1 })
+      done()
+    })
+    const plugin = {
+      plugin: Pino,
+      options: {
+        stream: stream,
+        level: 'info',
+        mergeHapiLogData: true
+      }
+    }
+
+    await server.register(plugin)
+    server.log(['info'], 1)
+    await finish
+  })
+
   test('respects `messageKey` option', async () => {
@@ -1765,3 +1856,3 @@ const server = getServer()
       expect(data.req.url).to.endWith('/foo')
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] put \/foo 404 \(\d*ms\)/)
       resolver()
@@ -1803,3 +1894,3 @@ })
       expect(data.req.url).to.endWith('/foo')
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] put \/foo 404 \(\d*ms\)/)
       resolver()
@@ -1841,3 +1932,3 @@ })
       expect(data.req.url).to.endWith('/foo')
-      expect(data.msg).to.equal('request completed')
+      expect(data.msg).to.match(/\[response\] put \/foo 404 \(\d*ms\)/)
       resolver()
@@ -1844,0 +1935,0 @@ })

No alert changes

Improved metrics

Total package byte prevSize

82695

increased by3.43%

Lines of code

2554

increased by3.03%

Number of lines in readme file

310

increased by0.98%

Dependency changes

• Updated@hapi/hoek@^9.2.1

• Updated@types/hapi__hapi@^20.0.10

• Updatedabstract-logging@^2.0.1

• Updatedpino@^7.8.1