feat: add additional information to response log

CHANGELOG.md

@@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 ### Added
 
 - new fields params in `url` field in incoming request and request completed logs
+- add additional information to response logs
 
 ## v4.0.0 - 2021-04-20
 

docs/logging.md

@@ -3,3 +3,24 @@
 The library generates logs following [Mia-Platform logging guidelines](https://docs.mia-platform.eu/docs/development_suite/monitoring-dashboard/dev_ops_guide/log).
 
 For a json schema example check [test log schema file](../tests/log.schema.json)
+
+## Additional information to response logs
+
+It is possible to add custom information to request completed logs.
+In your handler, or in a hook (before the onResponse hook which write the response log), you could add to the fastify reply object an `additionalRequestCompletedLogInfo` field.
+This field must be an object, and will be added to the request completed log.
+
+For example: 
+
+```js
+fastify.post('/items/:itemId', {
+  onRequest: function (req, reply, done) {
+    reply.additionalRequestCompletedLogInfo = {
+      custom: 'property',
+    }
+    done()
+  }
+}, function handler(request, reply) {
+  reply.send({ created: 'true' })
+})
+```

lib/custom-logger.js

@@ -71,8 +71,9 @@ function logIncomingRequest(req, reply, next) {
 
 function logRequestCompleted(req, reply, next) {
   const { method, url, headers, params } = req
-  const { statusCode } = reply
+  const { statusCode, additionalRequestCompletedLogInfo } = reply
   req.log.info({
+    ...additionalRequestCompletedLogInfo,
     http: {
       request: {
         method,

tests/launch-fastify.test.js

@@ -347,6 +347,94 @@ test('Test custom serializers', t => {
     await fastifyInstance.close()
   })
 
+  t.test('fields values - with custom properties on response log', async assert => {
+    assert.plan(18)
+    const stream = split(JSON.parse)
+
+    stream.once('data', () => {
+      stream.once('data', line => {
+        assert.equal(line.reqId, '34')
+        assert.equal(line.level, 10)
+        assert.notOk(line.req)
+        assert.strictSame(line.http, {
+          request: {
+            method: 'POST',
+            userAgent: { original: 'lightMyRequest' },
+          },
+        })
+        assert.strictSame(line.url, { path: '/items/my-item', params: { itemId: 'my-item' } })
+        assert.strictSame(line.host, { hostname: 'testHost', forwardedHostame: 'testForwardedHost', ip: 'testIp' })
+
+        stream.once('data', secondLine => {
+          assert.equal(line.reqId, '34')
+          assert.equal(secondLine.level, 30)
+          assert.notOk(secondLine.res)
+          assert.ok(secondLine.responseTime)
+          assert.strictSame(secondLine.http, {
+            request: {
+              method: 'POST',
+              userAgent: { original: 'lightMyRequest' },
+            },
+            response: {
+              statusCode: 200,
+              body: { bytes: 18 },
+            },
+          })
+          assert.strictSame(secondLine.url, { path: '/items/my-item', params: { itemId: 'my-item' } })
+          assert.strictSame(secondLine.host, { hostname: 'testHost', forwardedHost: 'testForwardedHost', ip: 'testIp' })
+          assert.strictSame(secondLine.custom, 'property')
+
+          stream.once('data', () => {
+            stream.once('data', thirdLine => {
+              assert.ok(thirdLine.responseTime)
+              assert.strictSame(thirdLine.http, {
+                request: {
+                  method: 'GET',
+                  userAgent: { original: 'lightMyRequest' },
+                },
+                response: {
+                  statusCode: 200,
+                  body: { bytes: 13 },
+                },
+              })
+              assert.strictSame(thirdLine.url, { path: '/items/my-item', params: { itemId: 'my-item' } })
+              assert.strictSame(thirdLine.custom, undefined)
+
+              assert.end()
+            })
+          })
+        })
+      })
+    })
+
+    const fastifyInstance = await launch('./tests/modules/correct-module', {
+      logLevel: 'trace',
+      stream,
+    })
+    await fastifyInstance.inject({
+      method: 'POST',
+      url: '/items/my-item',
+      headers: {
+        'x-forwarded-for': 'testIp',
+        'host': 'testHost:3000',
+        'x-forwarded-host': 'testForwardedHost',
+        'x-request-id': '34',
+      },
+    })
+    await fastifyInstance.inject({
+      method: 'GET',
+      url: '/items/my-item',
+      headers: {
+        'x-forwarded-for': 'testIp',
+        'host': 'testHost:3000',
+        'x-forwarded-host': 'testForwardedHost',
+        'x-request-id': '34',
+      },
+    })
+
+    await fastifyInstance.close()
+  })
+
   t.end()
 })
 

tests/modules/correct-module.js

@@ -36,6 +36,13 @@ module.exports = async function plugin(fastify, config) {
   fastify.get('/items/:itemId', function emptyContentLength(request, reply) {
     reply.send({ config })
   })
+  fastify.post('/items/:itemId', function handler(request, reply) {
+    reply.additionalRequestCompletedLogInfo = {
+      custom: 'property',
+    }
+
+    reply.send({ created: 'true' })
+  })
 }
 
 module.exports.options = {