Fix/df 469 forbidden error logs

src/config/index.ts

@@ -55,7 +55,7 @@ export const config = convict({
   },
   enforceCsrf: {
     format: Boolean,
-    default: isProduction,
+    default: true,
     env: 'ENFORCE_CSRF'
   },
 

src/server/common/helpers/logging/forward-logs.test.ts

@@ -0,0 +1,104 @@
+import { type RequestEvent } from '@hapi/hapi'
+import type pino from 'pino'
+
+import { forwardLogs } from '~/src/server/common/helpers/logging/forward-logs.js'
+
+describe('forwardLogs', () => {
+  let logger: pino.Logger
+
+  beforeEach(() => {
+    const info = jest.fn()
+    const error = jest.fn()
+
+    logger = { error, info } as unknown as pino.Logger
+  })
+
+  it('logs info with string data', () => {
+    forwardLogs(
+      logger,
+      {
+        channel: 'app',
+        timestamp: Date.now().toString(),
+        tags: ['a', 'b', 'c'],
+        data: 'My log msg'
+      } as RequestEvent,
+      { a: true, b: true, c: true }
+    )
+
+    expect(logger.info).toHaveBeenCalledExactlyOnceWith(
+      'Channel: app, Tags: [a,b,c], Data: My log msg'
+    )
+  })
+
+  it('logs info with undefined data', () => {
+    forwardLogs(
+      logger,
+      {
+        channel: 'app',
+        timestamp: Date.now().toString(),
+        tags: ['a', 'b', 'c']
+      } as RequestEvent,
+      { a: true, b: true, c: true }
+    )
+
+    expect(logger.info).toHaveBeenCalledExactlyOnceWith(
+      'Channel: app, Tags: [a,b,c], Data: type - undefined'
+    )
+  })
+
+  it('logs info with object data', () => {
+    forwardLogs(
+      logger,
+      {
+        channel: 'app',
+        timestamp: Date.now().toString(),
+        tags: ['a', 'b', 'c'],
+        data: { some: 'data' }
+      } as RequestEvent,
+      { a: true, b: true, c: true }
+    )
+
+    expect(logger.info).toHaveBeenCalledExactlyOnceWith(
+      'Channel: app, Tags: [a,b,c], Data: type - object'
+    )
+  })
+
+  it('logs info with function data', () => {
+    forwardLogs(
+      logger,
+      {
+        channel: 'app',
+        timestamp: Date.now().toString(),
+        tags: ['a', 'b', 'c'],
+        data: () => {
+          ''
+        }
+      } as RequestEvent,
+      { a: true, b: true, c: true }
+    )
+
+    expect(logger.info).toHaveBeenCalledExactlyOnceWith(
+      'Channel: app, Tags: [a,b,c], Data: type - function'
+    )
+  })
+
+  it('logs error with string data', () => {
+    const error = new Error('Some error')
+
+    forwardLogs(
+      logger,
+      {
+        channel: 'internal',
+        timestamp: Date.now().toString(),
+        tags: ['a', 'b', 'c', 'error'],
+        error
+      } as RequestEvent,
+      { a: true, b: true, c: true, error: true }
+    )
+
+    expect(logger.error).toHaveBeenCalledWith(
+      error,
+      'Channel: internal, Tags: [a,b,c,error], Error: Some error'
+    )
+  })
+})

src/server/common/helpers/logging/forward-logs.ts

@@ -0,0 +1,45 @@
+import { getErrorMessage } from '@defra/forms-model'
+import {
+  type LogEvent,
+  type RequestEvent,
+  type ServerRegisterPluginObject
+} from '@hapi/hapi'
+import type pino from 'pino'
+
+export const forwardLogs = (
+  logger: pino.Logger,
+  event: LogEvent | RequestEvent,
+  tags: Record<string, true>
+) => {
+  const tagstr = event.tags.join(',')
+  const message = `Channel: ${event.channel}, Tags: [${tagstr}]`
+
+  if ('error' in tags) {
+    logger.error(
+      event.error,
+      `${message}, Error: ${getErrorMessage(event.error)}`
+    )
+  } else {
+    const data =
+      typeof event.data === 'string'
+        ? event.data
+        : `type - ${typeof event.data}`
+
+    logger.info(`${message}, Data: ${data}`)
+  }
+}
+
+export default {
+  plugin: {
+    name: 'forward-logs',
+    register: (server) => {
+      server.events.on('log', (event, tags) =>
+        forwardLogs(server.logger, event, tags)
+      )
+
+      server.events.on('request', (request, event, tags) =>
+        forwardLogs(request.logger, event, tags)
+      )
+    }
+  }
+} satisfies ServerRegisterPluginObject<void>

src/server/index.ts

@@ -25,6 +25,7 @@ import blipp from 'blipp'
 import { ProxyAgent } from 'proxy-agent'
 
 import { config } from '~/src/config/index.js'
+import forwardLogs from '~/src/server/common/helpers/logging/forward-logs.js'
 import { requestLogger } from '~/src/server/common/helpers/logging/request-logger.js'
 import { requestTracing } from '~/src/server/common/helpers/logging/request-tracing.js'
 import { buildRedisClient } from '~/src/server/common/helpers/redis-client.js'
@@ -180,6 +181,7 @@ export async function createServer(routeConfig?: RouteConfig) {
   const server = hapi.server(serverOptions())
 
   await server.register(requestLogger)
+  await server.register(forwardLogs)
 
   if (config.get('isProduction')) {
     prepareSecureContext(server)

src/server/plugins/errorPages.ts

@@ -39,14 +39,6 @@ export default {
             return h.view('404', viewModel).code(statusCode)
           }
 
-          request.log('error', {
-            statusCode,
-            // eslint-disable-next-line @typescript-eslint/no-unsafe-assignment
-            data: response.data,
-            message: response.message,
-            stack: response.stack
-          })
-
           const error = new Error(
             `HTTP ${statusCode} error: ${response.message}`
           )

src/server/plugins/nunjucks/context.js

@@ -3,8 +3,7 @@ import { basename, join } from 'node:path'
 
 import {
   checkFormStatus,
-  encodeUrl,
-  safeGenerateCrumb
+  encodeUrl
 } from '@defra/forms-engine-plugin/engine/helpers.js'
 import Boom from '@hapi/boom'
 import { StatusCodes } from 'http-status-codes'
@@ -59,7 +58,6 @@ export function context(request) {
       serviceName: config.get('serviceName'),
       serviceVersion: config.get('serviceVersion')
     },
-    crumb: safeGenerateCrumb(request),
     cspNonce: request?.plugins.blankie?.nonces?.script,
     currentPath: request ? `${request.path}${request.url.search}` : undefined,
     previewMode: isPreviewMode ? formState : undefined,

src/server/plugins/nunjucks/context.test.js

@@ -105,36 +105,6 @@ describe('Nunjucks context', () => {
         malformedRequest.server.plugins.crumb.generate
       ).not.toHaveBeenCalled()
     })
-
-    it('should generate crumb when state exists', () => {
-      const mockCrumb = 'generated-crumb-value'
-      const validRequest = /** @type {FormRequest} */ (
-        /** @type {unknown} */ ({
-          server: {
-            plugins: {
-              crumb: {
-                generate: jest.fn().mockReturnValue(mockCrumb)
-              }
-            }
-          },
-          plugins: {},
-          route: {
-            settings: {
-              plugins: {}
-            }
-          },
-          path: '/test',
-          url: { search: '' },
-          state: {}
-        })
-      )
-
-      const { crumb } = context(validRequest)
-      expect(crumb).toBe(mockCrumb)
-      expect(validRequest.server.plugins.crumb.generate).toHaveBeenCalledWith(
-        validRequest
-      )
-    })
   })
 })
 

src/server/routes/save-and-exit-with-cache.test.js

@@ -17,7 +17,9 @@ describe('Save-and-exit check routes', () => {
   let server
 
   beforeAll(async () => {
-    server = await createServer()
+    server = await createServer({
+      enforceCsrf: false
+    })
     await server.initialize()
   })
 

src/server/routes/save-and-exit.test.js

@@ -18,7 +18,9 @@ describe('Save-and-exit check routes', () => {
   let server
 
   beforeAll(async () => {
-    server = await createServer()
+    server = await createServer({
+      enforceCsrf: false
+    })
     await server.initialize()
   })
 

test/form/cookies.test.js

@@ -30,7 +30,8 @@ describe(`Cookie banner and analytics`, () => {
   ])('shows the cookie banner by default', async (path) => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
     await server.initialize()
 
@@ -59,7 +60,8 @@ describe(`Cookie banner and analytics`, () => {
   ])('confirms when the user has accepted analytics cookies', async (path) => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
 
     await server.initialize()
@@ -111,7 +113,8 @@ describe(`Cookie banner and analytics`, () => {
   ])('confirms when the user has rejected analytics cookies', async (path) => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
 
     await server.initialize()
@@ -163,7 +166,8 @@ describe(`Cookie banner and analytics`, () => {
   ])('hides the cookie banner once dismissed', async (path) => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
 
     await server.initialize()
@@ -220,7 +224,8 @@ describe(`Cookie preferences`, () => {
     async ({ text, value }) => {
       server = await createServer({
         formFileName: 'basic.js',
-        formFilePath: join(import.meta.dirname, 'definitions')
+        formFilePath: join(import.meta.dirname, 'definitions'),
+        enforceCsrf: false
       })
       await server.initialize()
 
@@ -266,7 +271,8 @@ describe(`Cookie preferences`, () => {
   test("doesn't show the success banner if the user hasn't been posted from the cookie preferences page", async () => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
     await server.initialize()
 
@@ -308,7 +314,8 @@ describe(`Cookie preferences`, () => {
   test('defaults to no if one is not provided', async () => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
     await server.initialize()
 
@@ -327,7 +334,8 @@ describe(`Cookie preferences`, () => {
   test('returns bad request for invalid redirect urls', async () => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
     await server.initialize()
 

test/form/save-and-exit.test.js

@@ -20,7 +20,8 @@ describe('Save and exit', () => {
   beforeAll(async () => {
     server = await createServer({
       formFileName: 'basic.js',
-      formFilePath: join(import.meta.dirname, 'definitions')
+      formFilePath: join(import.meta.dirname, 'definitions'),
+      enforceCsrf: false
     })
 
     await server.initialize()