Merge pull request #2696 from alphagov/pp-13118-fix-correlation-id

PP-13118 Fix issues with correlation id

app/clients/base/request-context.js

@@ -3,13 +3,16 @@
 const { CORRELATION_ID } = require('@govuk-pay/pay-js-commons').logging.keys
 
 const { AsyncLocalStorage } = require('async_hooks')
-const { CORRELATION_HEADER } = require('../../../config')
+const crypto = require('crypto')
 
 const asyncLocalStorage = new AsyncLocalStorage()
 
 function requestContextMiddleware (req, res, next) {
   asyncLocalStorage.run({}, () => {
-    asyncLocalStorage.getStore()[CORRELATION_ID] = req.headers[CORRELATION_HEADER]
+    const correlationId = req.headers[CORRELATION_ID] || crypto.randomBytes(16).toString('hex')
+
+    asyncLocalStorage.getStore()[CORRELATION_ID] =  correlationId
+
     next()
   })
 }

app/clients/base/request-context.test.js

@@ -0,0 +1,104 @@
+'use strict'
+
+const proxyquire = require('proxyquire')
+const sinon = require('sinon')
+const { CORRELATION_ID } = require('@govuk-pay/pay-js-commons').logging.keys
+
+const { expect } = require('chai')
+
+let asyncStorageMock = {}
+
+function getRequestContext () {
+  return proxyquire('./request-context', {
+    'crypto': {
+      randomBytes : function () {
+        return 'test-correlation-id'
+      }
+    },
+    'async_hooks': {
+      AsyncLocalStorage : function () {
+        return {
+          getStore: function (){
+            return asyncStorageMock
+          },
+          run: function (object, callback) {
+            callback()
+          }
+        }
+      }
+    }
+  })
+}
+
+describe('Request Context', () => {
+  beforeEach(() => {
+    asyncStorageMock = {} 
+  })
+
+  it('sets the correlation id when there is no x-request-id header', () => {
+    const requestContext = getRequestContext()
+
+    const req = {
+      headers: {}
+    }
+    const res = null 
+    const next = sinon.spy()
+
+    requestContext.requestContextMiddleware(req, res, next)
+    expect(asyncStorageMock[CORRELATION_ID]).to.equal('test-correlation-id')
+    sinon.assert.calledWithExactly(next)
+  })
+
+  it('sets the correlation id using the x-request-id header when it exists', () => {
+    const requestContext = getRequestContext()
+    const xRequestIdHeaderValue = 'x-request-id-value' 
+
+    const req = {
+      headers: {}
+    }
+
+    req.headers[CORRELATION_ID] = xRequestIdHeaderValue
+
+    const res = null 
+    const next = sinon.spy()
+
+    requestContext.requestContextMiddleware(req, res, next)
+    expect(asyncStorageMock[CORRELATION_ID]).to.equal('x-request-id-value')
+    sinon.assert.calledWithExactly(next)
+  })
+
+  it('check it can add a field to the request context', () => {
+    const testKey = 'test-key'
+    const testValue = 'test-value'
+
+    const requestContext = getRequestContext()
+
+    requestContext.addField(testKey, testValue)
+    expect(asyncStorageMock[testKey]).to.equal(testValue)
+  })
+
+  it('get the correlation id from the async storage', () => {
+    const testCorrelationId = 'test-correlation-id'
+    asyncStorageMock[CORRELATION_ID] = testCorrelationId
+    const requestContext = getRequestContext()
+
+    const correlationId = requestContext.getRequestCorrelationIDField()
+    expect(correlationId).to.equal(testCorrelationId)
+  })
+
+  it('get the loggingFields from the async storage', () => {
+    const testKey1 = 'test-key-1'
+    const testKey2 = 'test-key-2'
+    const testValue1 = 'test-value-1'
+    const testValue2 = 'test-value-2'
+
+    asyncStorageMock[testKey1] = testValue1
+    asyncStorageMock[testKey2] = testValue2
+
+    const requestContext = getRequestContext()
+
+    const loggingFields = requestContext.getLoggingFields()
+    expect(loggingFields[testKey1]).to.equal(testValue1)
+    expect(loggingFields[testKey2]).to.equal(testValue2)
+  })
+})

app/middleware/resolve-payment-and-product.js

@@ -4,29 +4,29 @@
 const { renderErrorView } = require('../utils/response')
 const productsClient = require('../clients/products/products.client')
 const adminusersClient = require('../clients/adminusers/adminusers.client')
-const { addLoggingField } = require('../utils/log-context')
+const { addField } = require('../clients/base/request-context')
 const { GATEWAY_ACCOUNT_ID, SERVICE_EXTERNAL_ID, PAYMENT_EXTERNAL_ID, PRODUCT_EXTERNAL_ID } = require('@govuk-pay/pay-js-commons').logging.keys
 
 module.exports = function (req, res, next) {
   const { paymentExternalId } = req.params
   const correlationId = req.correlationId
   productsClient.payment.getByPaymentExternalId(paymentExternalId)
     .then(payment => {
-      addLoggingField(PAYMENT_EXTERNAL_ID, payment.externalId)
+      addField(PAYMENT_EXTERNAL_ID, payment.externalId)
       req.payment = res.locals.payment = payment
       return productsClient.product.getByProductExternalId(payment.productExternalId)
     })
     .then(product => {
       req.product = res.locals.product = product
-      addLoggingField(PRODUCT_EXTERNAL_ID, product.externalId)
+      addField(PRODUCT_EXTERNAL_ID, product.externalId)
       return product
     })
     .then(product => {
-      addLoggingField(GATEWAY_ACCOUNT_ID, product.gatewayAccountId)
+      addField(GATEWAY_ACCOUNT_ID, product.gatewayAccountId)
       return adminusersClient.getServiceByGatewayAccountId(product.gatewayAccountId, correlationId)
     })
     .then(service => {
-      addLoggingField(SERVICE_EXTERNAL_ID, service.externalId)
+      addField(SERVICE_EXTERNAL_ID, service.externalId)
       req.service = service
       res.locals.service = service
       next()

app/middleware/resolve-product.js

@@ -5,23 +5,23 @@ const { renderErrorView } = require('../utils/response')
 const productsClient = require('../clients/products/products.client')
 const adminusersClient = require('../clients/adminusers/adminusers.client')
 const { GATEWAY_ACCOUNT_ID, SERVICE_EXTERNAL_ID, PRODUCT_EXTERNAL_ID } = require('@govuk-pay/pay-js-commons').logging.keys
-const { addLoggingField } = require('../utils/log-context')
+const { addField } = require('../clients/base/request-context')
 
 module.exports = function (req, res, next) {
   const { productExternalId } = req.params
   productsClient.product.getByProductExternalId(productExternalId)
     .then(product => {
-      addLoggingField(PRODUCT_EXTERNAL_ID, product.externalId)
+      addField(PRODUCT_EXTERNAL_ID, product.externalId)
       req.product = product
       res.locals.product = product
       return product
     })
     .then(product => {
-      addLoggingField(GATEWAY_ACCOUNT_ID, product.gatewayAccountId)
+      addField(GATEWAY_ACCOUNT_ID, product.gatewayAccountId)
       return adminusersClient.getServiceByGatewayAccountId(product.gatewayAccountId, req.correlationId)
     })
     .then(service => {
-      addLoggingField(SERVICE_EXTERNAL_ID, service.externalId)
+      addField(SERVICE_EXTERNAL_ID, service.externalId)
       req.service = service
       res.locals.service = service
       next()

app/routes.js

@@ -22,8 +22,6 @@ const { validateAndRefreshCsrf, ensureSessionHasCsrfSecret } = require('./middle
 const resolveProduct = require('./middleware/resolve-product')
 const resolvePaymentAndProduct = require('./middleware/resolve-payment-and-product')
 const resolveLanguage = require('./middleware/resolve-language')
-// - Middleware
-const correlationId = require('./middleware/correlation-id')
 
 // Assignments
 const { healthcheck, staticPaths, friendlyUrl, pay, demoPayment, paymentLinks } = paths
@@ -35,9 +33,6 @@ module.exports.paths = paths
 module.exports.bind = function (app) {
   app.get('/style-guide', (req, res) => response(req, res, 'style_guide'))
 
-  // APPLY CORRELATION MIDDLEWARE
-  app.use('*', correlationId)
-
   // HEALTHCHECK
   app.get(healthcheck.path, healthcheckCtrl)
 

app/utils/logger.js

@@ -2,7 +2,7 @@ const { createLogger, format, transports } = require('winston')
 const { json, splat, prettyPrint } = format
 const { govUkPayLoggingFormat } = require('@govuk-pay/pay-js-commons').logging
 const { addSentryToErrorLevel } = require('./sentry.js')
-const { getLoggingFields } = require('./log-context')
+const { getLoggingFields } = require('../clients/base/request-context')
 
 const supplementSharedLoggingFields = format((info) => {
   if (getLoggingFields()) {

config/server.js

@@ -25,7 +25,7 @@ const cookieUtil = require('../app/utils/cookie')
 const i18nConfig = require('./i18n')
 const logger = require('../app/utils/logger')(__filename)
 const loggingMiddleware = require('../app/middleware/logging-middleware')
-const { logContextMiddleware } = require('../app/utils/log-context')
+const { requestContextMiddleware } = require('../app/clients/base/request-context')
 const Sentry = require('../app/utils/sentry.js').initialiseSentry()
 const replaceParamsInPath = require('../app/utils/replace-params-in-path')
 
@@ -52,7 +52,7 @@ const APP_VIEWS = [
 
 function initialiseGlobalMiddleware (app) {
   app.use(cookieParser())
-  app.use(logContextMiddleware)
+  app.use(requestContextMiddleware)
   logger.stream = {
     write: function (message) {
       logger.info(message)