Filter asset requests from Hapi-pino logs

.env.example

@@ -14,7 +14,8 @@ POSTGRES_DB_TEST=sroc_charge_test
 # Server config
 PORT=3000
 
-# Test config
+# Log config
+LOG_ASSET_REQUESTS=false
 LOG_IN_TEST=false
 
 # External services

app/plugins/hapi_pino.plugin.js

@@ -9,8 +9,11 @@
  *
  * @module HapiPinoPlugin
  */
+
 const HapiPino = require('hapi-pino')
 
+const HapiPinoIgnoreRequestService = require('../services/plugins/hapi_pino_ignore_request.service.js')
+
 /**
  * Return test configuration options for the logger
  *
@@ -48,8 +51,10 @@ const HapiPinoPlugin = logInTest => {
       transport: process.env.NODE_ENV !== 'production' ? { target: 'pino-pretty', options: { colorize: true } } : undefined,
       // Redact Authorization headers, see https://getpino.io/#/docs/redaction
       redact: ['req.headers.authorization'],
-      // We don't want logs outputting for our 'health' routes
-      ignorePaths: ['/', '/status']
+      // We want our logs to focus on the main requests and not become full of 'noise' from requests for /assets or
+      // pings from the AWS load balancer to /status. We pass this function to hapi-pino to control what gets filtered
+      // https://github.com/pinojs/hapi-pino#optionsignorefunc-options-request--boolean
+      ignoreFunc: HapiPinoIgnoreRequestService.go
     }
   }
 }

app/server.js

@@ -3,7 +3,7 @@
 const Hapi = require('@hapi/hapi')
 
 const ServerConfig = require('../config/server.config.js')
-const TestConfig = require('../config/test.config.js')
+const LogConfig = require('../config/log.config.js')
 
 const AirbrakePlugin = require('./plugins/airbrake.plugin.js')
 const BlippPlugin = require('./plugins/blipp.plugin.js')
@@ -19,7 +19,7 @@ const registerPlugins = async (server) => {
   await server.register(StopPlugin)
   await server.register(require('@hapi/inert'))
   await server.register(RouterPlugin)
-  await server.register(HapiPinoPlugin(TestConfig.logInTest))
+  await server.register(HapiPinoPlugin(LogConfig.logInTest))
   await server.register(AirbrakePlugin)
   await server.register(ErrorPagesPlugin)
   await server.register(RequestNotifierPlugin)

app/services/plugins/hapi_pino_ignore_request.service.js

@@ -0,0 +1,59 @@
+'use strict'
+
+/**
+ * @module HapiPinoIgnoreRequestService
+ */
+
+const LogConfig = require('../../../config/log.config.js')
+
+class HapiPinoIgnoreRequestService {
+  /**
+   * Returns true or false whether a request should be loged
+   *
+   * Used by `app/plugins/hapi_pino.plugin.js` to control what does and doesn't get added to our log output. We built
+   * `/status` to support AWS load balancer health checks which fire approximately every 500ms. If we logged these
+   * requests our log would be too noisy to prove useful. (`/` and `/status` go to the same place hence both are
+   * listed).
+   *
+   * When a view is requested, a number of assets will be requested along with it. So, a single request for a page will
+   * result in the following log entries
+   *
+   * ```text
+   * [09:41:06.763] INFO (17542): [response] get /service-status 200 (1138ms)
+   * [09:41:06.871] INFO (17542): [response] get /assets/stylesheets/application.css 200 (72ms)
+   * [09:41:06.873] INFO (17542): [response] get /assets/all.js 200 (64ms)
+   * [09:41:06.893] INFO (17542): [response] get /assets/images/govuk-crest.png 200 (8ms)
+   * [09:41:06.926] INFO (17542): [response] get /assets/fonts/light-94a07e06a1-v2.woff2 200 (19ms)
+   * [09:41:06.928] INFO (17542): [response] get /assets/fonts/bold-b542beb274-v2.woff2 200 (18ms)
+   * [09:41:07.032] INFO (17542): [response] get /assets/images/favicon.ico 200 (6ms)
+   * ```
+   *
+   * And these are just the first line from each entry. Because we log both the request and response details when
+   * viewed locally each entry is 41 lines long!
+   *
+   * So, we also do not log any requests to `/assets/*`.
+   *
+   * @param {Object} _options The options passed to the HapiPino plugin
+   * @param {request} request Hapi request object created internally for each incoming request
+   *
+   * @returns {boolean} true if the request should be ignored, else false
+   */
+  static go (_options, request) {
+    const staticPaths = ['/', '/status']
+
+    // If request is a known path ignore it
+    if (staticPaths.includes(request.path)) {
+      return true
+    }
+
+    // If logging asset requests is disabled and the request is for an asset ignore it
+    if (!LogConfig.logAssetRequests && request.path.startsWith('/assets')) {
+      return true
+    }
+
+    // Do not ignore all other requests
+    return false
+  }
+}
+
+module.exports = HapiPinoIgnoreRequestService

config/test.config.js → config/log.config.js

@@ -3,6 +3,7 @@
 const config = {
   // Credit to https://stackoverflow.com/a/323546/6117745 for how to handle
   // converting the env var to a boolean
+  logAssetRequests: (String(process.env.LOG_ASSET_REQUESTS) === 'true') || false,
   logInTest: (String(process.env.LOG_IN_TEST) === 'true') || false
 }
 

test/services/plugins/hapi_pino_ignore_request.service.test.js

@@ -0,0 +1,73 @@
+'use strict'
+
+// Test framework dependencies
+const Lab = require('@hapi/lab')
+const Code = require('@hapi/code')
+const Sinon = require('sinon')
+
+const { describe, it, beforeEach, afterEach } = exports.lab = Lab.script()
+const { expect } = Code
+
+// Things we need to stub
+const LogConfig = require('../../../config/log.config')
+
+// Thing under test
+const HapiPinoIgnoreRequestService = require('../../../app/services/plugins/hapi_pino_ignore_request.service.js')
+
+describe('Hapi Pino Ignore Request service', () => {
+  const _options = {}
+
+  afterEach(() => {
+    Sinon.restore()
+  })
+
+  describe("when the request is for the root '/'", () => {
+    it('returns true', () => {
+      const result = HapiPinoIgnoreRequestService.go(_options, { path: '/' })
+
+      expect(result).to.be.true()
+    })
+  })
+
+  describe("when the request is for '/status'", () => {
+    it('returns true', () => {
+      const result = HapiPinoIgnoreRequestService.go(_options, { path: '/status' })
+
+      expect(result).to.be.true()
+    })
+  })
+
+  describe('when the request is for an asset', () => {
+    describe('and LOG_ASSET_REQUESTS is false', () => {
+      beforeEach(() => {
+        Sinon.replace(LogConfig, 'logAssetRequests', false)
+      })
+
+      it('returns true', () => {
+        const result = HapiPinoIgnoreRequestService.go(_options, { path: '/assets/stylesheets/application.css' })
+
+        expect(result).to.be.true()
+      })
+    })
+
+    describe('and LOG_ASSET_REQUESTS is true', () => {
+      beforeEach(() => {
+        Sinon.replace(LogConfig, 'logAssetRequests', true)
+      })
+
+      it('returns false', () => {
+        const result = HapiPinoIgnoreRequestService.go(_options, { path: '/assets/stylesheets/application.css' })
+
+        expect(result).to.be.false()
+      })
+    })
+  })
+
+  describe("when the request is not for '/status' or an asset", () => {
+    it('returns false', () => {
+      const result = HapiPinoIgnoreRequestService.go(_options, { path: '/bill-run/stuff' })
+
+      expect(result).to.be.false()
+    })
+  })
+})