diff --git a/src/__mocks__/logger-mocks.js b/src/__mocks__/logger-mocks.js index 259c090da..07f28d78a 100644 --- a/src/__mocks__/logger-mocks.js +++ b/src/__mocks__/logger-mocks.js @@ -1,5 +1,5 @@ import { vi } from 'vitest' -import { LogCodes } from '~/src/server/common/helpers/logging/log-codes-definition.js' +import { LogCodes } from '~/src/server/common/helpers/logging/log-codes/definition.js' export const mockLoggerFactory = () => ({ info: vi.fn(), @@ -15,14 +15,14 @@ export const mockLoggerFactoryWithCustomMethods = (customMethods = {}) => ({ /** * @typedef {Object} MockLogCodesDefinition - * @property {import('~/src/server/common/helpers/logging/log-codes-definition.js').LogTypes.LogLevel} level + * @property {import('~/src/server/common/helpers/logging/log-codes/definition.js').LogTypes.LogLevel} level * @property {import('vitest').Mock} messageFunc */ /** * Auto-generate mock LogCodes from real LogCodes * Each messageFunc becomes a vi.fn() for test assertions - * @param {typeof import('~/src/server/common/helpers/logging/log-codes-definition.js').LogCodes} codes + * @param {typeof import('~/src/server/common/helpers/logging/log-codes/definition.js').LogCodes} codes * @returns {Record>} */ const autoMockLogCodes = (codes) => diff --git a/src/contracts/grants-ui-gas.contract.test.js b/src/contracts/grants-ui-gas.contract.test.js index 363b84116..8ff42aa6d 100644 --- a/src/contracts/grants-ui-gas.contract.test.js +++ b/src/contracts/grants-ui-gas.contract.test.js @@ -8,11 +8,10 @@ vi.mock('../server/common/helpers/retry.js', () => ({ retry: (operation) => operation() })) -vi.mock('../server/common/helpers/logging/log.js', () => ({ - debug: vi.fn(), - log: vi.fn(), - logger: { debug: vi.fn(), info: vi.fn(), error: vi.fn(), warn: vi.fn() } -})) +vi.mock('../server/common/helpers/logging/log.js', async () => { + const { mockLogHelper } = await import('../__mocks__/logger-mocks.js') + return mockLogHelper() +}) function createProvider() { return new PactV4({ diff --git a/src/contracts/v1/land-grants.client.contract.test.js b/src/contracts/v1/land-grants.client.contract.test.js index 64d9747e5..896bd7138 100644 --- a/src/contracts/v1/land-grants.client.contract.test.js +++ b/src/contracts/v1/land-grants.client.contract.test.js @@ -3,18 +3,10 @@ import path from 'path' import { vi } from 'vitest' import { postToLandGrantsApi } from '~/src/server/land-grants/services/land-grants.client' -vi.mock('~/src/server/common/helpers/logging/log.js', () => ({ - LogCodes: { - LAND_GRANTS: { - API_REQUEST: { level: 'info', messageFunc: vi.fn() } - } - }, - log: vi.fn(), - debug: vi.fn(), - logger: { - debug: vi.fn() - } -})) +vi.mock('~/src/server/common/helpers/logging/log.js', async () => { + const { mockLogHelper } = await import('~/src/__mocks__/logger-mocks.js') + return mockLogHelper() +}) vi.mock('~/src/server/common/helpers/retry.js', () => ({ retry: (operation) => operation() diff --git a/src/contracts/v2/land-grants.client.contract.test.js b/src/contracts/v2/land-grants.client.contract.test.js index 17507cf4d..912274b96 100644 --- a/src/contracts/v2/land-grants.client.contract.test.js +++ b/src/contracts/v2/land-grants.client.contract.test.js @@ -4,18 +4,10 @@ import path from 'path' import { vi } from 'vitest' import { postToLandGrantsApi } from '~/src/server/land-grants/services/land-grants.client' -vi.mock('~/src/server/common/helpers/logging/log.js', () => ({ - LogCodes: { - LAND_GRANTS: { - API_REQUEST: { level: 'info', messageFunc: vi.fn() } - } - }, - log: vi.fn(), - debug: vi.fn(), - logger: { - debug: vi.fn() - } -})) +vi.mock('~/src/server/common/helpers/logging/log.js', async () => { + const { mockLogHelper } = await import('~/src/__mocks__/logger-mocks.js') + return mockLogHelper() +}) vi.mock('~/src/server/common/helpers/retry.js', () => ({ retry: (operation) => operation() diff --git a/src/server/agreements/controller.js b/src/server/agreements/controller.js index 28ed115cb..0aaa90957 100644 --- a/src/server/agreements/controller.js +++ b/src/server/agreements/controller.js @@ -2,7 +2,7 @@ import { config } from '~/src/config/config.js' import { statusCodes } from '~/src/server/common/constants/status-codes.js' import Jwt from '@hapi/jwt' import { SystemError } from '~/src/server/common/utils/errors/SystemError.js' -import { log, debug } from '~/src/server/common/helpers/logging/log.js' +import { log } from '~/src/server/common/helpers/logging/log.js' import { LogCodes } from '~/src/server/common/helpers/logging/log-codes.js' /** @@ -76,6 +76,19 @@ function buildProxyHeaders(token, request) { } } +function logAgreementsUpstreamError(request, error) { + log( + LogCodes.SYSTEM.EXTERNAL_API_ERROR, + { + endpoint: 'agreements', + service: 'farming-grants-agreements-ui', + upstreamStatus: error.statusCode ?? error.output?.statusCode ?? error.status ?? null, + errorMessage: error.message + }, + request + ) +} + /** * Controller for the agreements API * @satisfies {Partial} @@ -108,7 +121,7 @@ export const getAgreementController = { return apiResponse } catch (error) { - debug(LogCodes.SYSTEM.EXTERNAL_API_ERROR, { endpoint: 'agreements', errorMessage: error.message }, request) + logAgreementsUpstreamError(request, error) if (error.message.includes('Missing required configuration')) { return h diff --git a/src/server/agreements/controller.test.js b/src/server/agreements/controller.test.js index ff148430c..7b29d4997 100644 --- a/src/server/agreements/controller.test.js +++ b/src/server/agreements/controller.test.js @@ -3,6 +3,7 @@ import { getAgreementController } from './controller.js' import { config } from '~/src/config/config.js' import Jwt from '@hapi/jwt' import { mockHapiRequest, mockHapiResponseToolkit } from '~/src/__mocks__/hapi-mocks.js' +import { log } from '~/src/server/common/helpers/logging/log.js' vi.mock('~/src/config/config.js', async () => { const { mockConfigSimple } = await import('~/src/__mocks__') @@ -449,6 +450,25 @@ describe('Agreements Controller', () => { }) }) + test('should log EXTERNAL_API_ERROR with service and upstreamStatus on proxy 5xx', async () => { + const proxyError = new Error('Bad Gateway') + proxyError.output = { statusCode: 502 } + mockH.proxy.mockRejectedValue(proxyError) + + await getAgreementController.handler(mockRequest, mockH) + + expect(log).toHaveBeenCalledWith( + expect.objectContaining({ level: 'error' }), + expect.objectContaining({ + endpoint: 'agreements', + service: 'farming-grants-agreements-ui', + upstreamStatus: 502, + errorMessage: 'Bad Gateway' + }), + mockRequest + ) + }) + test('should not include error details in production', async () => { const originalNodeEnv = process.env.NODE_ENV process.env.NODE_ENV = 'production' diff --git a/src/server/auth/services/whitelist.service.js b/src/server/auth/services/whitelist.service.js index 9884c95e9..5dbe4b5c8 100644 --- a/src/server/auth/services/whitelist.service.js +++ b/src/server/auth/services/whitelist.service.js @@ -122,7 +122,7 @@ class WhitelistService { /** * Helper method to log whitelist events with consistent structure * @param {object} logCode - Logging options. - * @param {import('../../common/helpers/logging/log-codes-definition.js').LogTypes.LogLevel} logCode.level - The log level. + * @param {import('../../common/helpers/logging/log-codes/definition.js').LogTypes.LogLevel} logCode.level - The log level. * @param {Function} logCode.messageFunc - A function that creates an interpolated message string * @param {string} crn - The user's CRN * @param {string} sbi - The SBI number diff --git a/src/server/common/helpers/errors.js b/src/server/common/helpers/errors.js index d7e33fafd..db2dd56e8 100644 --- a/src/server/common/helpers/errors.js +++ b/src/server/common/helpers/errors.js @@ -15,6 +15,7 @@ import { config } from '~/src/config/config.js' import { BaseError } from '~/src/server/common/utils/errors/BaseError.js' const UNKNOWN_USER = 'unknown' +const SERVER_ERROR_RANGE_END = 600 export const HTTP_STATUS = { BAD_REQUEST: 400, @@ -74,6 +75,24 @@ function statusCodeMessage(statusCode) { } } +/** + * Reads the upstream HTTP status from a thrown error wrapped by Boom, so it can + * be attached to the SERVER_ERROR log payload. When a downstream service + * (e.g. grants-ui-backend) responds with 5xx, the call site throws an Error + * with `code`/`status` set; `boomify` mutates that error in place to add Boom + * fields without removing the original properties. + * @param {ErrorResponse} response + * @returns {number | null} + */ +function getUpstreamStatus(response) { + const candidate = response?.code ?? response?.status ?? null + return typeof candidate === 'number' && + candidate >= statusCodes.internalServerError && + candidate < SERVER_ERROR_RANGE_END + ? candidate + : null +} + /** * @param { AnyRequest } request * @param { ResponseToolkit } h @@ -86,6 +105,7 @@ export function catchAll(request, h) { } let statusCode + let upstreamStatus = null if (response instanceof BaseError) { const rootErrors = BaseError.findRootErrors(response) @@ -95,7 +115,8 @@ export function catchAll(request, h) { statusCode = response.details.status || statusCodes.internalServerError } else { statusCode = response.output.statusCode || statusCodes.internalServerError - handleErrorLogging(request, response, statusCode) + upstreamStatus = getUpstreamStatus(response) + handleErrorLogging(request, response, statusCode, upstreamStatus) } // Handle redirects properly @@ -106,9 +127,15 @@ export function catchAll(request, h) { return renderErrorView(h, statusCode) } -function handleErrorLogging(request, response, statusCode) { +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {number} statusCode + * @param {number | null} [upstreamStatus] + */ +function handleErrorLogging(request, response, statusCode, upstreamStatus = null) { if (statusCode >= statusCodes.internalServerError) { - handleServerErrors(request, response, statusCode) + handleServerErrors(request, response, statusCode, upstreamStatus) } else if (statusCode >= statusCodes.badRequest) { handleClientErrors(request, response, statusCode) } else { @@ -116,7 +143,13 @@ function handleErrorLogging(request, response, statusCode) { } } -function handleServerErrors(request, response, statusCode) { +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {number} statusCode + * @param {number | null} [upstreamStatus] + */ +function handleServerErrors(request, response, statusCode, upstreamStatus = null) { const errorContext = analyzeError(request, response) if (errorContext.isAuthError && !errorContext.alreadyLogged) { @@ -124,7 +157,7 @@ function handleServerErrors(request, response, statusCode) { } else if (errorContext.isBellError && !errorContext.alreadyLogged) { logBellError(request, response, errorContext) } else if (!errorContext.isAuthError && !errorContext.isBellError && !errorContext.alreadyLogged) { - logSystemError(request, response, statusCode) + logSystemError(request, response, statusCode, upstreamStatus) } else { // Error already logged, skip to avoid duplicates } @@ -132,6 +165,11 @@ function handleServerErrors(request, response, statusCode) { logDebugInformation(request, response, statusCode, errorContext) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @returns {ErrorContext} + */ function analyzeError(request, response) { return { isAuthError: request.path?.startsWith('/auth'), @@ -140,6 +178,10 @@ function analyzeError(request, response) { } } +/** + * @param {ErrorResponse} response + * @returns {boolean | undefined} + */ function isBellRelatedError(response) { return ( response?.message?.includes('bell') || @@ -149,6 +191,11 @@ function isBellRelatedError(response) { ) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {ErrorContext} errorContext + */ function logAuthError(request, response, errorContext) { log( LogCodes.AUTH.SIGN_IN_FAILURE, @@ -162,6 +209,11 @@ function logAuthError(request, response, errorContext) { ) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {ErrorContext} errorContext + */ function logBellError(request, response, errorContext) { log( LogCodes.AUTH.SIGN_IN_FAILURE, @@ -175,6 +227,12 @@ function logBellError(request, response, errorContext) { ) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {ErrorContext} errorContext + * @returns {Record} + */ function buildAuthContext(request, response, errorContext) { return { path: request.path, @@ -194,12 +252,19 @@ function buildAuthContext(request, response, errorContext) { } } -function logSystemError(request, response, statusCode) { +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {number} statusCode + * @param {number | null} [upstreamStatus] + */ +function logSystemError(request, response, statusCode, upstreamStatus = null) { log( LogCodes.SYSTEM.SERVER_ERROR, { errorMessage: response?.message || 'Internal server error', statusCode, + ...(upstreamStatus ? { upstreamStatus } : {}), path: request.path, method: request.method, stack: response?.stack @@ -208,6 +273,12 @@ function logSystemError(request, response, statusCode) { ) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {number} statusCode + * @param {ErrorContext} errorContext + */ function logDebugInformation(request, response, statusCode, errorContext) { const errorMessage = statusCodeMessage(statusCode) @@ -241,9 +312,14 @@ function logDebugInformation(request, response, statusCode, errorContext) { ) } +/** + * @param {AnyRequest} request + * @param {ErrorResponse} response + * @param {number} statusCode + */ function handleClientErrors(request, response, statusCode) { if (statusCode === statusCodes.locked) { - // Expected business condition – no system error log + // Expected business condition - no system error log return } const errorMessage = statusCodeMessage(statusCode) @@ -298,7 +374,7 @@ function tryParseForm(path, errorMsg) { /** * Parse resource path to determine type and context * @param {string} path - Request path - * @param {object} response - Response object + * @param {ErrorResponse} response - Response object * @returns {{type: string, identifier: string, reason: string}} */ function parseResourcePath(path, response) { @@ -315,7 +391,7 @@ function parseResourcePath(path, response) { /** * Handle 404 errors with detailed context logging * @param {AnyRequest} request - * @param {object} response + * @param {ErrorResponse} response */ function handle404WithContext(request, response) { const path = request.path || 'unknown' @@ -357,6 +433,10 @@ function handle404WithContext(request, response) { } } +/** + * @param {ResponseToolkit} h + * @param {number} statusCode + */ function renderErrorView(h, statusCode) { // SonarQube does not like this being set as the default for the switch, it's apparently a critical issue. let errorView @@ -395,6 +475,17 @@ function renderErrorView(h, statusCode) { } /** + * @typedef {Object} ErrorContext + * @property {boolean} [isAuthError] - Whether the request is for an /auth path + * @property {boolean} [alreadyLogged] - Whether the error has already been logged upstream + * @property {boolean} [isBellError] - Whether the error originates from Bell/OAuth + * + * @typedef {Boom & { code?: number, status?: number, alreadyLogged?: boolean }} ErrorResponse + * A Boom error, optionally augmented with `code`/`status` (set by upstream + * client code before `boomify` wraps the Error) and `alreadyLogged` (set by + * handlers that have already emitted a log entry to suppress duplicates). + * + * @import { Boom } from '@hapi/boom' * @import { AnyRequest } from '@defra/forms-engine-plugin/engine/types.js' * @import { ResponseToolkit } from '@hapi/hapi' */ diff --git a/src/server/common/helpers/errors.test.js b/src/server/common/helpers/errors.test.js index 717afe35a..f862a697a 100644 --- a/src/server/common/helpers/errors.test.js +++ b/src/server/common/helpers/errors.test.js @@ -191,6 +191,26 @@ describe('#catchAll', () => { expect(mockToolkitCode).toHaveBeenCalledWith(statusCodes.imATeapot) }) + test('Should include upstreamStatus in the SERVER_ERROR log payload when the response carries an upstream 5xx', () => { + const request = mockRequest(statusCodes.internalServerError) + request.response.code = statusCodes.badGateway + request.response.status = statusCodes.badGateway + + catchAll(request, mockToolkit) + + expect(log).toHaveBeenCalledWith( + expect.objectContaining({ level: 'error' }), + expect.objectContaining({ + upstreamStatus: statusCodes.badGateway, + statusCode: statusCodes.internalServerError + }), + request + ) + // Response status is unchanged — 500 stays 500 user-facing. + expect(mockToolkitView).toHaveBeenCalledWith('errors/500', { supportEmail: null }) + expect(mockToolkitCode).toHaveBeenCalledWith(statusCodes.internalServerError) + }) + test('Should provide expected "Something went wrong" page and log error for internalServerError', () => { catchAll(mockRequest(statusCodes.internalServerError), mockToolkit) diff --git a/src/server/common/helpers/lock/application-lock.js b/src/server/common/helpers/lock/application-lock.js index 7a3a963a3..a14ec17a7 100644 --- a/src/server/common/helpers/lock/application-lock.js +++ b/src/server/common/helpers/lock/application-lock.js @@ -1,10 +1,27 @@ import { createApiHeadersForGrantsUiBackend } from '../auth/backend-auth-helper.js' -import { log, debug, LogCodes } from '~/src/server/common/helpers/logging/log.js' +import { log, LogCodes } from '~/src/server/common/helpers/logging/log.js' import { mintLockReleaseToken } from './lock-token.js' import { config } from '~/src/config/config.js' const GRANTS_UI_BACKEND_ENDPOINT = config.get('session.cache.apiEndpoint') +function logLockReleaseError(err, urlHref, ownerId, timeoutMs) { + if (err.name === 'AbortError') { + log(LogCodes.APPLICATION_LOCKS.RELEASE_TIMEOUT, { + ownerId, + timeoutMs + }) + } else { + log(LogCodes.SYSTEM.EXTERNAL_API_ERROR, { + method: 'DELETE', + endpoint: urlHref, + service: 'grants-ui-backend', + identity: ownerId, + errorMessage: err.message + }) + } +} + /** * Releases all application locks held by a given user via the grants-ui-backend API. * @@ -61,8 +78,10 @@ export async function releaseAllApplicationLocksForOwnerFromApi({ ownerId }) { log(LogCodes.SYSTEM.EXTERNAL_API_ERROR, { method: 'DELETE', endpoint: url.href, + service: 'grants-ui-backend', + upstreamStatus: response.status, identity: ownerId, - errorMessage: `${response.status} - ${response.statusText}` + errorMessage: response.statusText }) return { ok: false, releasedCount: 0 } } @@ -74,19 +93,7 @@ export async function releaseAllApplicationLocksForOwnerFromApi({ ownerId }) { }) return { ok: true, releasedCount: body.releasedCount ?? 0 } } catch (err) { - if (err.name === 'AbortError') { - debug(LogCodes.APPLICATION_LOCKS.RELEASE_TIMEOUT, { - ownerId, - timeoutMs - }) - } else { - debug(LogCodes.SYSTEM.EXTERNAL_API_ERROR, { - method: 'DELETE', - endpoint: url.href, - identity: ownerId, - errorMessage: err.message - }) - } + logLockReleaseError(err, url.href, ownerId, timeoutMs) return { ok: false, releasedCount: 0 } } finally { clearTimeout(timeoutId) diff --git a/src/server/common/helpers/lock/application-lock.test.js b/src/server/common/helpers/lock/application-lock.test.js index dd27ecbef..260fc35f4 100644 --- a/src/server/common/helpers/lock/application-lock.test.js +++ b/src/server/common/helpers/lock/application-lock.test.js @@ -19,7 +19,6 @@ vi.mock('./lock-token.js', () => ({ let releaseAllApplicationLocksForOwnerFromApi let log -let debug let LogCodes describe('releaseAllApplicationLocksForOwnerFromApi', () => { @@ -37,7 +36,6 @@ describe('releaseAllApplicationLocksForOwnerFromApi', () => { releaseAllApplicationLocksForOwnerFromApi = helper.releaseAllApplicationLocksForOwnerFromApi const logModule = await import('~/src/server/common/helpers/logging/log.js') log = logModule.log - debug = logModule.debug LogCodes = logModule.LogCodes vi.clearAllMocks() createApiHeadersForGrantsUiBackend.mockReturnValue({ Authorization: 'Bearer token' }) @@ -85,7 +83,9 @@ describe('releaseAllApplicationLocksForOwnerFromApi', () => { expect(log).toHaveBeenCalledWith( LogCodes.SYSTEM.EXTERNAL_API_ERROR, expect.objectContaining({ - errorMessage: '500 - Internal Server Error' + service: 'grants-ui-backend', + upstreamStatus: 500, + errorMessage: 'Internal Server Error' }) ) }) @@ -96,9 +96,10 @@ describe('releaseAllApplicationLocksForOwnerFromApi', () => { const result = await releaseAllApplicationLocksForOwnerFromApi({ ownerId }) expect(result).toEqual({ ok: false, releasedCount: 0 }) - expect(debug).toHaveBeenCalledWith( + expect(log).toHaveBeenCalledWith( LogCodes.SYSTEM.EXTERNAL_API_ERROR, expect.objectContaining({ + service: 'grants-ui-backend', errorMessage: 'Network failure' }) ) @@ -125,7 +126,7 @@ describe('releaseAllApplicationLocksForOwnerFromApi', () => { expect(result).toEqual({ ok: false, releasedCount: 0 }) - expect(debug).toHaveBeenCalledWith( + expect(log).toHaveBeenCalledWith( LogCodes.APPLICATION_LOCKS.RELEASE_TIMEOUT, expect.objectContaining({ ownerId @@ -149,7 +150,6 @@ describe('releaseAllApplicationLocksForOwnerFromApi', () => { const logModule = await import('~/src/server/common/helpers/logging/log.js') log = logModule.log - debug = logModule.debug vi.clearAllMocks() }) diff --git a/src/server/common/helpers/logging/log-codes-definition.js b/src/server/common/helpers/logging/log-codes-definition.js deleted file mode 100644 index 550159a36..000000000 --- a/src/server/common/helpers/logging/log-codes-definition.js +++ /dev/null @@ -1,507 +0,0 @@ -/** - * @namespace LogTypes - * @typedef {"info"|"warn"|"error"|"debug"} LogTypes.LogLevel - * - * @typedef { Object } LogCodesDefinition - * @property {LogTypes.LogLevel} level - The log level (e.g., 'info', 'warn', 'error', 'debug'). - * @property {(messageOptions: Object) => string} messageFunc - A function that takes message options and returns a formatted log message string. - */ - -/** - * @type {Object>} - */ -export const LogCodes = { - AUTH: { - GENERIC_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Authentication error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` - }, - SIGN_IN_ATTEMPT: { - level: 'info', - messageFunc: (messageOptions) => `User sign-in attempt for user=${messageOptions.userId || 'unknown'}` - }, - SIGN_IN_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `User sign-in successful for user=${messageOptions.userId}, organisation=${messageOptions.organisationId}` - }, - SIGN_IN_FAILURE: { - level: 'error', - messageFunc: (messageOptions) => - `User sign-in failed for user=${messageOptions.userId || 'unknown'}. Error: ${messageOptions.errorMessage}` - }, - SIGN_OUT: { - level: 'info', - messageFunc: (messageOptions) => - `User sign-out for user=${messageOptions.userId}, session=${messageOptions.sessionId}` - }, - TOKEN_VERIFICATION_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `Token verification successful for userCRN=${messageOptions.userId}, userSBI=${messageOptions.organisationId}` - }, - TOKEN_VERIFICATION_FAILURE: { - level: 'error', - messageFunc: (messageOptions) => - `Token verification failed for user=${messageOptions.userId || 'unknown'}. Error: ${messageOptions.errorMessage}` - }, - SESSION_EXPIRED: { - level: 'info', - messageFunc: (messageOptions) => - `Session expired for user=${messageOptions.userId}, session=${messageOptions.sessionId}` - }, - UNAUTHORIZED_ACCESS: { - level: 'error', - messageFunc: (messageOptions) => - `Unauthorized access attempt to path=${messageOptions.path} from user=${messageOptions.userId || 'unknown'}` - }, - AUTH_DEBUG: { - level: 'debug', - messageFunc: (messageOptions) => - `Auth debug for path=${messageOptions.path}: isAuthenticated=${messageOptions.isAuthenticated}, strategy=${messageOptions.strategy}, mode=${messageOptions.mode}, hasCredentials=${messageOptions.hasCredentials}, hasToken=${messageOptions.hasToken}, hasProfile=${messageOptions.hasProfile}, userAgent=${messageOptions.userAgent}, referer=${messageOptions.referer}, queryParams=${JSON.stringify(messageOptions.queryParams)}, authError=${messageOptions.authError}` - }, - WHITELIST_ACCESS_GRANTED: { - level: 'info', - messageFunc: (messageOptions) => - `Whitelist access granted to path=${messageOptions.path} for user=${messageOptions.userId || 'unknown'}, sbi=${messageOptions.sbi || 'N/A'}: ${messageOptions.validationType || 'validation passed'}` - }, - WHITELIST_ACCESS_DENIED_BOTH: { - level: 'info', - messageFunc: (messageOptions) => - `Whitelist access denied to path=${messageOptions.path}: Both CRN ${messageOptions.userId || 'unknown'} and SBI ${messageOptions.sbi || 'unknown'} failed validation` - }, - WHITELIST_ACCESS_DENIED_CRN_PASSED: { - level: 'info', - messageFunc: (messageOptions) => - `Whitelist access denied to path=${messageOptions.path}: CRN ${messageOptions.userId || 'unknown'} passed but SBI ${messageOptions.sbi || 'unknown'} failed validation` - }, - WHITELIST_ACCESS_DENIED_SBI_PASSED: { - level: 'info', - messageFunc: (messageOptions) => - `Whitelist access denied to path=${messageOptions.path}: SBI ${messageOptions.sbi || 'unknown'} passed but CRN ${messageOptions.userId || 'unknown'} failed validation` - }, - CREDENTIALS_MISSING: { - level: 'error', - messageFunc: () => 'No credentials received from Bell OAuth provider' - }, - TOKEN_MISSING: { - level: 'error', - messageFunc: () => 'No token received from Defra Identity' - }, - INVALID_STATE: { - level: 'error', - messageFunc: (messageOptions) => - `Invalid OAuth state provided | reason=${messageOptions.reason} | storedStatePresent=${messageOptions.storedStatePresent}` - } - }, - FORMS: { - FORM_LOAD: { - level: 'info', - messageFunc: (messageOptions) => - `Form loaded: ${messageOptions.formName} for user=${messageOptions.userId || 'unknown'}` - }, - FORM_SUBMIT: { - level: 'info', - messageFunc: (messageOptions) => - `Form submitted: ${messageOptions.formName} by user=${messageOptions.userId || 'unknown'}` - }, - FORM_VALIDATION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Form validation error in ${messageOptions.formName}: ${messageOptions.errorMessage}` - }, - FORM_VALIDATION_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => `Form validation successful for ${messageOptions.formName}` - }, - FORM_PROCESSING_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Form processing error for ${messageOptions.formName}: ${messageOptions.errorMessage}` - }, - FORM_SAVE: { - level: 'info', - messageFunc: (messageOptions) => - `Form saved: ${messageOptions.formName} for user=${messageOptions.userId || 'unknown'}` - }, - SLUG_STORED: { - level: 'debug', - messageFunc: (messageOptions) => `${messageOptions.controller}: Storing slug in context: ${messageOptions.slug}` - }, - SLUG_RESOLVED: { - level: 'debug', - messageFunc: (messageOptions) => `${messageOptions.controller}: ${messageOptions.message}` - } - }, - SUBMISSION: { - SUBMISSION_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `Grant submission successful for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}` - }, - SUBMISSION_COMPLETED: { - level: 'info', - messageFunc: (messageOptions) => - `Form submission completed for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}, fields=${messageOptions.numberOfFields || 0}, status=${messageOptions.status}` - }, - SUBMISSION_FAILURE: { - level: 'error', - messageFunc: (messageOptions) => - `Grant submission failed for grantType=${messageOptions.grantType}, userCrn=${messageOptions.userCrn}, userSbi=${messageOptions.userSbi}, error=${messageOptions.errorMessage}` - }, - SUBMISSION_VALIDATION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Submission validation error for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}, validationId=${messageOptions.validationId}` - }, - SUBMISSION_PAYLOAD_LOG: { - level: 'debug', - messageFunc: (messageOptions) => - `Submission payload for grantType=${messageOptions.grantType}:\n${JSON.stringify(messageOptions.payload, null, 2)}` - }, - SUBMISSION_REDIRECT_FAILURE: { - level: 'error', - messageFunc: (messageOptions) => - `Submission redirect failure for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}. Error: ${messageOptions.errorMessage}` - }, - VALIDATOR_NOT_FOUND: { - level: 'error', - messageFunc: (messageOptions) => `No validator found for grantType=${messageOptions.grantType}` - }, - APPLICATION_STATUS_UPDATED: { - level: 'debug', - messageFunc: (messageOptions) => - `${messageOptions.controller}: Application status updated to ${messageOptions.status}` - }, - SUBMISSION_PROCESSING: { - level: 'debug', - messageFunc: (messageOptions) => - `${messageOptions.controller}: Processing form submission, path=${messageOptions.path}` - }, - SUBMISSION_REDIRECT: { - level: 'debug', - messageFunc: (messageOptions) => `${messageOptions.controller}: Redirecting to ${messageOptions.redirectPath}` - } - }, - DECLARATION: { - DECLARATION_LOAD: { - level: 'info', - messageFunc: (messageOptions) => - `Declaration page loaded for user=${messageOptions.userId}, grantType=${messageOptions.grantType}` - }, - DECLARATION_ACCEPTED: { - level: 'info', - messageFunc: (messageOptions) => - `Declaration accepted by user=${messageOptions.userId}, grantType=${messageOptions.grantType}` - }, - DECLARATION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Declaration processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` - } - }, - CONFIRMATION: { - CONFIRMATION_LOAD: { - level: 'info', - messageFunc: (messageOptions) => - `Confirmation page loaded for user=${messageOptions.userId}, grantType=${messageOptions.grantType}` - }, - CONFIRMATION_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `Confirmation processed successfully for user=${messageOptions.userId}, referenceNumber=${messageOptions.referenceNumber}` - }, - CONFIRMATION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Confirmation processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` - }, - SUBMITTED_STATUS_RETRIEVED: { - level: 'info', - messageFunc: (messageOptions) => - `${messageOptions.controller}: Retrieved submitted status for referenceNumber=${messageOptions.referenceNumber}` - } - }, - LAND_GRANTS: { - LAND_GRANT_APPLICATION_STARTED: { - level: 'info', - messageFunc: (messageOptions) => `Land grant application started for user=${messageOptions.userId}` - }, - LAND_GRANT_APPLICATION_SUBMITTED: { - level: 'info', - messageFunc: (messageOptions) => - `Land grant application submitted for user=${messageOptions.userId}, referenceNumber=${messageOptions.referenceNumber}` - }, - LAND_GRANT_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Land grant processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` - }, - NO_LAND_PARCELS_FOUND: { - level: 'warn', - messageFunc: (messageOptions) => `No land parcels found for sbi=${messageOptions.sbi}` - }, - NO_ACTIONS_FOUND: { - level: 'error', - messageFunc: (messageOptions) => - `No actions found | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` - }, - VALIDATE_APPLICATION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Error validating application: ${messageOptions.errorMessage} | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` - }, - FETCH_ACTIONS_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Error fetching actions: ${messageOptions.errorMessage} | sbi: ${messageOptions.sbi} | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` - }, - FARM_DETAILS_MISSING_FIELDS: { - level: 'warn', - messageFunc: (messageOptions) => - `Missing farm contact details for sbi: ${messageOptions.sbi} | fields: ${messageOptions.missingFields.join(', ')}` - }, - UNAUTHORISED_PARCEL: { - level: 'error', - messageFunc: (messageOptions) => - `Land parcel doesn't belong to sbi=${messageOptions.sbi} | selectedLandParcel: ${messageOptions.selectedLandParcel} | landParcelsForSbi=${JSON.stringify(messageOptions.landParcelsForSbi)}` - }, - API_REQUEST: { - level: 'info', - messageFunc: (messageOptions) => - `Land Grants API request | endpoint: ${messageOptions.endpoint} | url: ${messageOptions.url}` - } - }, - WOODLAND: { - VALIDATE_ERROR: { - level: 'error', - messageFunc: (messageOptions) => `Woodland validation error: ${messageOptions.errorMessage}` - } - }, - AGREEMENTS: { - AGREEMENT_LOAD: { - level: 'info', - messageFunc: (messageOptions) => - `Agreement loaded for user=${messageOptions.userId}, agreementType=${messageOptions.agreementType}` - }, - AGREEMENT_ACCEPTED: { - level: 'info', - messageFunc: (messageOptions) => - `Agreement accepted by user=${messageOptions.userId}, agreementType=${messageOptions.agreementType}` - }, - AGREEMENT_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Agreement processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` - }, - PROXY_RESPONSE_ERROR: { - level: 'error', - messageFunc: () => 'Proxy response is undefined. Possible upstream error or misconfiguration.' - } - }, - COOKIES: { - PAGE_LOAD: { - level: 'info', - messageFunc: (messageOptions) => - `Cookies page loaded: returnUrl=${messageOptions.returnUrl}, referer=${messageOptions.referer}` - } - }, - - RESOURCE_NOT_FOUND: { - FORM_NOT_FOUND: { - level: 'info', - messageFunc: (messageOptions) => - `Form not found: slug=${messageOptions.slug}, userId=${messageOptions.userId || 'anonymous'}, sbi=${messageOptions.sbi || 'unknown'}, reason=${messageOptions.reason || 'not_found'}, environment=${messageOptions.environment || 'unknown'}, referer=${messageOptions.referer || 'none'}` - }, - PAGE_NOT_FOUND: { - level: 'info', - messageFunc: (messageOptions) => - `Page not found: path=${messageOptions.path}, userId=${messageOptions.userId || 'anonymous'}, sbi=${messageOptions.sbi || 'unknown'}, referer=${messageOptions.referer || 'none'}, userAgent=${messageOptions.userAgent || 'unknown'}` - } - }, - APPLICATION_LOCKS: { - RELEASE_SKIPPED: { - level: 'debug', - messageFunc: ({ ownerId, reason }) => `Application locks release skipped | ownerId=${ownerId} | reason=${reason}` - }, - RELEASE_ATTEMPTED: { - level: 'debug', - messageFunc: ({ ownerId }) => `Attempting application locks release | ownerId=${ownerId}` - }, - RELEASE_SUCCEEDED: { - level: 'debug', - messageFunc: ({ ownerId, releasedCount }) => - `Application locks released | ownerId=${ownerId} | releasedCount=${releasedCount}` - }, - RELEASE_TIMEOUT: { - level: 'warn', - messageFunc: ({ ownerId, timeoutMs }) => - `Application locks release timed out | ownerId=${ownerId} | timeoutMs=${timeoutMs}` - }, - RELEASE_FAILED: { - level: 'error', - messageFunc: ({ ownerId, errorName, errorMessage }) => - `Failed to release application locks | ownerId=${ownerId} | errorName=${errorName} | errorMessage=${errorMessage}` - } - }, - PRINT_APPLICATION: { - SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => `Print application viewed for referenceNumber=${messageOptions.referenceNumber}` - }, - ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Print application error for user=${messageOptions.userId}, slug=${messageOptions.slug}: ${messageOptions.errorMessage}` - } - }, - SYSTEM: { - GENERIC_ERROR: { - level: 'error', - messageFunc: (messageOptions) => `An error occurred: ${messageOptions.errorMessage}` - }, - VIEW_DEBUG: { - level: 'debug', - messageFunc: (messageOptions) => - `View path debug: currentFile=${messageOptions.currentFilePath}, isBuilt=${messageOptions.isRunningBuiltCode}, basePath=${messageOptions.basePath}, workingDir=${messageOptions.processWorkingDir}, pathsResolved=${messageOptions.resolvedViewPaths?.length || 0}` - }, - VIEW_PATH_CHECK: { - level: 'debug', - messageFunc: (messageOptions) => - `View path ${messageOptions.index}: path=${messageOptions.path}, exists=${messageOptions.exists}, isAbsolute=${messageOptions.isAbsolute}` - }, - ENV_CONFIG_DEBUG: { - level: 'debug', - messageFunc: (messageOptions) => - `Environment configuration: ${messageOptions.configType} - ${JSON.stringify(messageOptions.configValues)}` - }, - SERVER_ERROR: { - level: 'error', - messageFunc: (messageOptions) => `Server error occurred: ${messageOptions.errorMessage}` - }, - STARTUP_PHASE: { - level: 'info', - messageFunc: (messageOptions) => `Startup phase: ${messageOptions.phase} - ${messageOptions.status}` - }, - PLUGIN_REGISTRATION: { - level: 'debug', - messageFunc: (messageOptions) => `Plugin registration: ${messageOptions.pluginName} - ${messageOptions.status}` - }, - SYSTEM_STARTUP: { - level: 'info', - messageFunc: (messageOptions) => `System startup completed on port=${messageOptions.port}` - }, - SYSTEM_SHUTDOWN: { - level: 'info', - messageFunc: () => 'System shutdown initiated' - }, - EXTERNAL_API_CALL: { - level: 'info', - messageFunc: (messageOptions) => - `External API call to ${messageOptions.endpoint} for user=${messageOptions.userId || 'unknown'}` - }, - EXTERNAL_API_CALL_DEBUG: { - level: 'debug', - messageFunc: (messageOptions) => - `External ${messageOptions.method} to ${new URL(messageOptions.endpoint).pathname} (${messageOptions.identity || 'unknown'})` - }, - EXTERNAL_API_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `External API error for ${messageOptions.endpoint}: ${messageOptions.errorMessage}` - }, - GAS_ACTION_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Error invoking GAS action ${messageOptions.action} for grant ${messageOptions.grantCode}: ${messageOptions.errorMessage}` - }, - BACKEND_AUTH_CONFIG_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `Backend auth configuration invalid | missingKeys=${messageOptions.missingKeys?.join(', ') || 'unknown'}` - }, - RELATIONSHIP_PARSE_ERROR: { - level: 'error', - messageFunc: (messageOptions) => - `extractFarmDetails: Invalid relationship format | relationships="${messageOptions.relationships}" | reason=${messageOptions.reason}` - }, - CONFIG_MISSING: { - level: 'error', - messageFunc: (messageOptions) => - `Missing required configuration: ${messageOptions?.missing?.join(', ') || 'unknown'}` - }, - CONFIG_INVALID: { - level: 'error', - messageFunc: (messageOptions) => - `Invalid configuration, key "${messageOptions.key}" is missing or invalid: ${messageOptions.value}` - }, - WHITELIST_CONFIG_INCOMPLETE: { - level: 'error', - messageFunc: (messageOptions) => - `Incomplete whitelist configuration in form "${messageOptions.formName}" | present=${messageOptions.presentVar} | missing=${messageOptions.missingVar}` - }, - CRN_ENV_VAR_MISSING: { - level: 'error', - messageFunc: (messageOptions) => - `CRN whitelist environment variable "${messageOptions.envVar}" missing for form "${messageOptions.formName}"` - }, - SBI_ENV_VAR_MISSING: { - level: 'error', - messageFunc: (messageOptions) => - `SBI whitelist environment variable "${messageOptions.envVar}" missing for form "${messageOptions.formName}"` - }, - INVALID_REDIRECT_RULES: { - level: 'error', - messageFunc: (messageOptions) => - `Invalid redirect rules in form "${messageOptions.formName}" | reason=${messageOptions.reason}` - }, - CONSOLIDATED_VIEW_API_ERROR: { - level: 'error', - messageFunc: (messageOptions) => { - const base = `Unexpected error fetching business data from Consolidated View API | sbi=${messageOptions.sbi || 'unknown'} | status=${messageOptions.statusCode || 'unknown'} | error=${messageOptions.errorMessage}` - return messageOptions.responseBody ? `${base} | responseBody=${messageOptions.responseBody}` : base - } - }, - CONSOLIDATED_VIEW_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `Consolidated View API request successful | sbi=${messageOptions.sbi || 'unknown'}` - }, - CONSOLIDATED_VIEW_PARTIAL_SUCCESS: { - level: 'info', - messageFunc: (messageOptions) => - `Partial success from Consolidated View API | sbi=${messageOptions.sbi || 'unknown'} | failedPaths=${messageOptions.failedPaths} | status=${messageOptions.statusCode || 'unknown'}` - }, - CONSOLIDATED_VIEW_ADDRESS_FORMAT: { - level: 'info', - messageFunc: (messageOptions) => - `Address format for sbi=${messageOptions.sbi} is ${messageOptions.uprn ? 'structured' : 'unstructured'}, uprn=${messageOptions.uprn || 'not set'}` - }, - SESSION_STATE_CLEAR_FAILED: { - level: 'error', - messageFunc: (messageOptions) => - `Failed to clear application state for slug=${messageOptions.slug}, sessionKey=${messageOptions.sessionKey}, error=${messageOptions.errorMessage}` - }, - SESSION_STATE_KEY_PARSE_FAILED: { - level: 'error', - messageFunc: (messageOptions) => - `Failed to parse session key: error=${messageOptions.errorMessage}, path=${messageOptions.requestPath}` - }, - SESSION_STATE_FETCH_FAILED: { - level: 'error', - messageFunc: (messageOptions) => - `Failed to fetch saved state: sessionKey=${messageOptions.sessionKey}, error=${messageOptions.errorMessage}, path=${messageOptions.requestPath}` - }, - RATE_LIMIT_EXCEEDED: { - level: 'warn', - messageFunc: (messageOptions) => - `Rate limit exceeded: path=${messageOptions.path}, ip=${messageOptions.ip || 'unknown'}, userId=${messageOptions.userId || 'anonymous'}, userAgent=${messageOptions.userAgent || 'unknown'}` - }, - STATE_SIZE_EXCEEDED: { - level: 'warn', - messageFunc: (messageOptions) => - `State payload size ${messageOptions.size} bytes exceeds limit of ${messageOptions.limit} bytes for sessionKey=${messageOptions.sessionKey}` - } - } -} diff --git a/src/server/common/helpers/logging/log-codes.js b/src/server/common/helpers/logging/log-codes.js index 63d3be26d..e1fea0c6d 100644 --- a/src/server/common/helpers/logging/log-codes.js +++ b/src/server/common/helpers/logging/log-codes.js @@ -1,5 +1,5 @@ import { validateLogCode } from './log-code-validator.js' -import { LogCodes } from './log-codes-definition.js' +import { LogCodes } from './log-codes/definition.js' // Re-export LogCodes from the definition file export { LogCodes } diff --git a/src/server/common/helpers/logging/log-codes.test.js b/src/server/common/helpers/logging/log-codes.test.js index 40b59d14c..dfcf640dc 100644 --- a/src/server/common/helpers/logging/log-codes.test.js +++ b/src/server/common/helpers/logging/log-codes.test.js @@ -143,6 +143,12 @@ describe('LogCodes', () => { 'error', { errorMessage: TEST_ERRORS.INVALID_TOKEN }, `Token verification failed for user=unknown. Error: ${TEST_ERRORS.INVALID_TOKEN}` + ], + [ + 'GENERIC_ERROR', + 'error', + { userId: TEST_USER_IDS.DEFAULT, errorMessage: TEST_ERRORS.INVALID_CREDENTIALS }, + `Authentication error for user=${TEST_USER_IDS.DEFAULT}: ${TEST_ERRORS.INVALID_CREDENTIALS}` ] ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { assertLogCode('AUTH', logCodeName, expectedLevel, testParams, expectedMessage) @@ -300,6 +306,18 @@ describe('LogCodes', () => { 'info', { formName: TEST_FORM_NAMES.DECLARATION }, `Form saved: ${TEST_FORM_NAMES.DECLARATION} for user=unknown` + ], + [ + 'SLUG_STORED', + 'debug', + { controller: 'DeclarationController', slug: 'example-grant' }, + 'DeclarationController: Storing slug in context: example-grant' + ], + [ + 'SLUG_RESOLVED', + 'debug', + { controller: 'DeclarationController', message: 'Resolved slug from context' }, + 'DeclarationController: Resolved slug from context' ] ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { assertLogCode('FORMS', logCodeName, expectedLevel, testParams, expectedMessage) @@ -519,6 +537,18 @@ describe('LogCodes', () => { 'info', { endpoint: '/api/v2/parcels', url: 'https://land-grants-api/api/v2/parcels' }, 'Land Grants API request | endpoint: /api/v2/parcels | url: https://land-grants-api/api/v2/parcels' + ], + [ + 'FARM_DETAILS_MISSING_FIELDS', + 'warn', + { sbi: TEST_SBI.DEFAULT, missingFields: ['email', 'telephone'] }, + `Missing farm contact details for sbi: ${TEST_SBI.DEFAULT} | fields: email, telephone` + ], + [ + 'FARM_DETAILS_MISSING_FIELDS with single field', + 'warn', + { sbi: TEST_SBI.DEFAULT, missingFields: ['email'] }, + `Missing farm contact details for sbi: ${TEST_SBI.DEFAULT} | fields: email` ] ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { assertLogCode('LAND_GRANTS', logCodeName, expectedLevel, testParams, expectedMessage) @@ -544,12 +574,63 @@ describe('LogCodes', () => { 'error', { userId: TEST_USER_IDS.DEFAULT, errorMessage: TEST_ERRORS.PROCESSING_FAILED }, `Agreement processing error for user=${TEST_USER_IDS.DEFAULT}: ${TEST_ERRORS.PROCESSING_FAILED}` - ] + ], + ['PROXY_RESPONSE_ERROR', 'error', {}, 'Proxy response is undefined. Possible upstream error or misconfiguration.'] ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { assertLogCode('AGREEMENTS', logCodeName, expectedLevel, testParams, expectedMessage) }) }) + describe('APPLICATION_LOCKS log codes', () => { + it.each([ + [ + 'RELEASE_SKIPPED', + 'debug', + { ownerId: 'session-abc', reason: 'no-owner' }, + 'Application locks release skipped | ownerId=session-abc | reason=no-owner' + ], + [ + 'RELEASE_ATTEMPTED', + 'debug', + { ownerId: 'session-abc' }, + 'Attempting application locks release | ownerId=session-abc' + ], + [ + 'RELEASE_SUCCEEDED', + 'debug', + { ownerId: 'session-abc', releasedCount: 3 }, + 'Application locks released | ownerId=session-abc | releasedCount=3' + ], + [ + 'RELEASE_TIMEOUT', + 'warn', + { ownerId: 'session-abc', timeoutMs: 5000 }, + 'Application locks release timed out | ownerId=session-abc | timeoutMs=5000' + ], + [ + 'RELEASE_FAILED', + 'error', + { ownerId: 'session-abc', errorName: 'TimeoutError', errorMessage: 'connection lost' }, + 'Failed to release application locks | ownerId=session-abc | errorName=TimeoutError | errorMessage=connection lost' + ] + ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { + assertLogCode('APPLICATION_LOCKS', logCodeName, expectedLevel, testParams, expectedMessage) + }) + }) + + describe('WOODLAND log codes', () => { + it.each([ + [ + 'VALIDATE_ERROR', + 'error', + { errorMessage: 'Invalid woodland data' }, + 'Woodland validation error: Invalid woodland data' + ] + ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { + assertLogCode('WOODLAND', logCodeName, expectedLevel, testParams, expectedMessage) + }) + }) + describe('COOKIES log codes', () => { it.each([ [ @@ -634,6 +715,18 @@ describe('LogCodes', () => { { errorMessage: TEST_ERRORS.DATABASE_ERROR }, `Server error occurred: ${TEST_ERRORS.DATABASE_ERROR}` ], + [ + 'SERVER_ERROR with upstreamStatus', + 'error', + { errorMessage: TEST_ERRORS.DATABASE_ERROR, upstreamStatus: 502 }, + `Server error occurred: ${TEST_ERRORS.DATABASE_ERROR} | upstreamStatus=502` + ], + [ + 'SERVER_ERROR with null upstreamStatus is omitted', + 'error', + { errorMessage: TEST_ERRORS.DATABASE_ERROR, upstreamStatus: null }, + `Server error occurred: ${TEST_ERRORS.DATABASE_ERROR}` + ], [ 'SYSTEM_STARTUP', 'info', @@ -664,6 +757,29 @@ describe('LogCodes', () => { { endpoint: TEST_ENDPOINTS.API_GRANTS, errorMessage: TEST_ERRORS.CONNECTION_FAILED }, `External API error for ${TEST_ENDPOINTS.API_GRANTS}: ${TEST_ERRORS.CONNECTION_FAILED}` ], + [ + 'EXTERNAL_API_ERROR with service and upstreamStatus', + 'error', + { + endpoint: TEST_ENDPOINTS.API_GRANTS, + errorMessage: TEST_ERRORS.CONNECTION_FAILED, + service: 'grants-ui-backend', + upstreamStatus: 502 + }, + `External API error for ${TEST_ENDPOINTS.API_GRANTS} | service=grants-ui-backend | upstreamStatus=502: ${TEST_ERRORS.CONNECTION_FAILED}` + ], + [ + 'EXTERNAL_API_ERROR with attempts after retry exhaustion', + 'error', + { + endpoint: TEST_ENDPOINTS.API_GRANTS, + errorMessage: TEST_ERRORS.CONNECTION_FAILED, + service: 'grants-ui-backend', + upstreamStatus: 502, + attempts: 3 + }, + `External API error for ${TEST_ENDPOINTS.API_GRANTS} | service=grants-ui-backend | upstreamStatus=502 | attempts=3: ${TEST_ERRORS.CONNECTION_FAILED}` + ], [ 'GAS_ACTION_ERROR', 'error', @@ -811,6 +927,77 @@ describe('LogCodes', () => { 'error', { errorMessage: 'Connection failed' }, 'Unexpected error fetching business data from Consolidated View API | sbi=unknown | status=unknown | error=Connection failed' + ], + [ + 'CONSOLIDATED_VIEW_API_ERROR with statusCode and responseBody', + 'error', + { + sbi: TEST_SBI.DEFAULT, + statusCode: 503, + errorMessage: 'Service Unavailable', + responseBody: '{"error":"upstream"}' + }, + `Unexpected error fetching business data from Consolidated View API | sbi=${TEST_SBI.DEFAULT} | status=503 | error=Service Unavailable | responseBody={"error":"upstream"}` + ], + [ + 'GENERIC_ERROR', + 'error', + { errorMessage: TEST_ERRORS.DATABASE_ERROR }, + `An error occurred: ${TEST_ERRORS.DATABASE_ERROR}` + ], + [ + 'CONFIG_INVALID', + 'error', + { key: 'apiUrl', value: 'not-a-url' }, + 'Invalid configuration, key "apiUrl" is missing or invalid: not-a-url' + ], + [ + 'CONSOLIDATED_VIEW_SUCCESS', + 'info', + { sbi: TEST_SBI.DEFAULT }, + `Consolidated View API request successful | sbi=${TEST_SBI.DEFAULT}` + ], + ['CONSOLIDATED_VIEW_SUCCESS with fallback', 'info', {}, 'Consolidated View API request successful | sbi=unknown'], + [ + 'CONSOLIDATED_VIEW_PARTIAL_SUCCESS', + 'info', + { sbi: TEST_SBI.DEFAULT, failedPaths: 'address,phone', statusCode: 207 }, + `Partial success from Consolidated View API | sbi=${TEST_SBI.DEFAULT} | failedPaths=address,phone | status=207` + ], + [ + 'CONSOLIDATED_VIEW_PARTIAL_SUCCESS with fallbacks', + 'info', + { failedPaths: 'address' }, + 'Partial success from Consolidated View API | sbi=unknown | failedPaths=address | status=unknown' + ], + [ + 'CONSOLIDATED_VIEW_ADDRESS_FORMAT structured', + 'info', + { sbi: TEST_SBI.DEFAULT, uprn: '12345' }, + `Address format for sbi=${TEST_SBI.DEFAULT} is structured, uprn=12345` + ], + [ + 'CONSOLIDATED_VIEW_ADDRESS_FORMAT unstructured', + 'info', + { sbi: TEST_SBI.DEFAULT }, + `Address format for sbi=${TEST_SBI.DEFAULT} is unstructured, uprn=not set` + ], + [ + 'RATE_LIMIT_EXCEEDED', + 'warn', + { + path: TEST_PATHS.EXAMPLE_GRANT, + ip: '127.0.0.1', + userId: TEST_USER_IDS.DEFAULT, + userAgent: 'Mozilla/5.0' + }, + `Rate limit exceeded: path=${TEST_PATHS.EXAMPLE_GRANT}, ip=127.0.0.1, userId=${TEST_USER_IDS.DEFAULT}, userAgent=Mozilla/5.0` + ], + [ + 'RATE_LIMIT_EXCEEDED with fallbacks', + 'warn', + { path: TEST_PATHS.EXAMPLE_GRANT }, + `Rate limit exceeded: path=${TEST_PATHS.EXAMPLE_GRANT}, ip=unknown, userId=anonymous, userAgent=unknown` ] ])('should have valid %s log code', (logCodeName, expectedLevel, testParams, expectedMessage) => { assertLogCode('SYSTEM', logCodeName, expectedLevel, testParams, expectedMessage) diff --git a/src/server/common/helpers/logging/log-codes/agreements.js b/src/server/common/helpers/logging/log-codes/agreements.js new file mode 100644 index 000000000..8ccc6c397 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/agreements.js @@ -0,0 +1,24 @@ +/** + * @type {Object} + */ +export const AGREEMENTS = { + AGREEMENT_LOAD: { + level: 'info', + messageFunc: (messageOptions) => + `Agreement loaded for user=${messageOptions.userId}, agreementType=${messageOptions.agreementType}` + }, + AGREEMENT_ACCEPTED: { + level: 'info', + messageFunc: (messageOptions) => + `Agreement accepted by user=${messageOptions.userId}, agreementType=${messageOptions.agreementType}` + }, + AGREEMENT_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Agreement processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` + }, + PROXY_RESPONSE_ERROR: { + level: 'error', + messageFunc: () => 'Proxy response is undefined. Possible upstream error or misconfiguration.' + } +} diff --git a/src/server/common/helpers/logging/log-codes/application-locks.js b/src/server/common/helpers/logging/log-codes/application-locks.js new file mode 100644 index 000000000..8e8507ac0 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/application-locks.js @@ -0,0 +1,28 @@ +/** + * @type {Object} + */ +export const APPLICATION_LOCKS = { + RELEASE_SKIPPED: { + level: 'debug', + messageFunc: ({ ownerId, reason }) => `Application locks release skipped | ownerId=${ownerId} | reason=${reason}` + }, + RELEASE_ATTEMPTED: { + level: 'debug', + messageFunc: ({ ownerId }) => `Attempting application locks release | ownerId=${ownerId}` + }, + RELEASE_SUCCEEDED: { + level: 'debug', + messageFunc: ({ ownerId, releasedCount }) => + `Application locks released | ownerId=${ownerId} | releasedCount=${releasedCount}` + }, + RELEASE_TIMEOUT: { + level: 'warn', + messageFunc: ({ ownerId, timeoutMs }) => + `Application locks release timed out | ownerId=${ownerId} | timeoutMs=${timeoutMs}` + }, + RELEASE_FAILED: { + level: 'error', + messageFunc: ({ ownerId, errorName, errorMessage }) => + `Failed to release application locks | ownerId=${ownerId} | errorName=${errorName} | errorMessage=${errorMessage}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/auth.js b/src/server/common/helpers/logging/log-codes/auth.js new file mode 100644 index 000000000..9f26b6e95 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/auth.js @@ -0,0 +1,87 @@ +/** + * @type {Object} + */ +export const AUTH = { + GENERIC_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Authentication error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` + }, + SIGN_IN_ATTEMPT: { + level: 'info', + messageFunc: (messageOptions) => `User sign-in attempt for user=${messageOptions.userId || 'unknown'}` + }, + SIGN_IN_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => + `User sign-in successful for user=${messageOptions.userId}, organisation=${messageOptions.organisationId}` + }, + SIGN_IN_FAILURE: { + level: 'error', + messageFunc: (messageOptions) => + `User sign-in failed for user=${messageOptions.userId || 'unknown'}. Error: ${messageOptions.errorMessage}` + }, + SIGN_OUT: { + level: 'info', + messageFunc: (messageOptions) => + `User sign-out for user=${messageOptions.userId}, session=${messageOptions.sessionId}` + }, + TOKEN_VERIFICATION_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => + `Token verification successful for userCRN=${messageOptions.userId}, userSBI=${messageOptions.organisationId}` + }, + TOKEN_VERIFICATION_FAILURE: { + level: 'error', + messageFunc: (messageOptions) => + `Token verification failed for user=${messageOptions.userId || 'unknown'}. Error: ${messageOptions.errorMessage}` + }, + SESSION_EXPIRED: { + level: 'info', + messageFunc: (messageOptions) => + `Session expired for user=${messageOptions.userId}, session=${messageOptions.sessionId}` + }, + UNAUTHORIZED_ACCESS: { + level: 'error', + messageFunc: (messageOptions) => + `Unauthorized access attempt to path=${messageOptions.path} from user=${messageOptions.userId || 'unknown'}` + }, + AUTH_DEBUG: { + level: 'debug', + messageFunc: (messageOptions) => + `Auth debug for path=${messageOptions.path}: isAuthenticated=${messageOptions.isAuthenticated}, strategy=${messageOptions.strategy}, mode=${messageOptions.mode}, hasCredentials=${messageOptions.hasCredentials}, hasToken=${messageOptions.hasToken}, hasProfile=${messageOptions.hasProfile}, userAgent=${messageOptions.userAgent}, referer=${messageOptions.referer}, queryParams=${JSON.stringify(messageOptions.queryParams)}, authError=${messageOptions.authError}` + }, + WHITELIST_ACCESS_GRANTED: { + level: 'info', + messageFunc: (messageOptions) => + `Whitelist access granted to path=${messageOptions.path} for user=${messageOptions.userId || 'unknown'}, sbi=${messageOptions.sbi || 'N/A'}: ${messageOptions.validationType || 'validation passed'}` + }, + WHITELIST_ACCESS_DENIED_BOTH: { + level: 'info', + messageFunc: (messageOptions) => + `Whitelist access denied to path=${messageOptions.path}: Both CRN ${messageOptions.userId || 'unknown'} and SBI ${messageOptions.sbi || 'unknown'} failed validation` + }, + WHITELIST_ACCESS_DENIED_CRN_PASSED: { + level: 'info', + messageFunc: (messageOptions) => + `Whitelist access denied to path=${messageOptions.path}: CRN ${messageOptions.userId || 'unknown'} passed but SBI ${messageOptions.sbi || 'unknown'} failed validation` + }, + WHITELIST_ACCESS_DENIED_SBI_PASSED: { + level: 'info', + messageFunc: (messageOptions) => + `Whitelist access denied to path=${messageOptions.path}: SBI ${messageOptions.sbi || 'unknown'} passed but CRN ${messageOptions.userId || 'unknown'} failed validation` + }, + CREDENTIALS_MISSING: { + level: 'error', + messageFunc: () => 'No credentials received from Bell OAuth provider' + }, + TOKEN_MISSING: { + level: 'error', + messageFunc: () => 'No token received from Defra Identity' + }, + INVALID_STATE: { + level: 'error', + messageFunc: (messageOptions) => + `Invalid OAuth state provided | reason=${messageOptions.reason} | storedStatePresent=${messageOptions.storedStatePresent}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/confirmation.js b/src/server/common/helpers/logging/log-codes/confirmation.js new file mode 100644 index 000000000..5cc8d1176 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/confirmation.js @@ -0,0 +1,25 @@ +/** + * @type {Object} + */ +export const CONFIRMATION = { + CONFIRMATION_LOAD: { + level: 'info', + messageFunc: (messageOptions) => + `Confirmation page loaded for user=${messageOptions.userId}, grantType=${messageOptions.grantType}` + }, + CONFIRMATION_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => + `Confirmation processed successfully for user=${messageOptions.userId}, referenceNumber=${messageOptions.referenceNumber}` + }, + CONFIRMATION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Confirmation processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` + }, + SUBMITTED_STATUS_RETRIEVED: { + level: 'info', + messageFunc: (messageOptions) => + `${messageOptions.controller}: Retrieved submitted status for referenceNumber=${messageOptions.referenceNumber}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/cookies.js b/src/server/common/helpers/logging/log-codes/cookies.js new file mode 100644 index 000000000..c045ecefd --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/cookies.js @@ -0,0 +1,10 @@ +/** + * @type {Object} + */ +export const COOKIES = { + PAGE_LOAD: { + level: 'info', + messageFunc: (messageOptions) => + `Cookies page loaded: returnUrl=${messageOptions.returnUrl}, referer=${messageOptions.referer}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/declaration.js b/src/server/common/helpers/logging/log-codes/declaration.js new file mode 100644 index 000000000..c2a07a720 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/declaration.js @@ -0,0 +1,20 @@ +/** + * @type {Object} + */ +export const DECLARATION = { + DECLARATION_LOAD: { + level: 'info', + messageFunc: (messageOptions) => + `Declaration page loaded for user=${messageOptions.userId}, grantType=${messageOptions.grantType}` + }, + DECLARATION_ACCEPTED: { + level: 'info', + messageFunc: (messageOptions) => + `Declaration accepted by user=${messageOptions.userId}, grantType=${messageOptions.grantType}` + }, + DECLARATION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Declaration processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/definition.js b/src/server/common/helpers/logging/log-codes/definition.js new file mode 100644 index 000000000..571a067b0 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/definition.js @@ -0,0 +1,41 @@ +import { AUTH } from './auth.js' +import { FORMS } from './forms.js' +import { SUBMISSION } from './submission.js' +import { DECLARATION } from './declaration.js' +import { CONFIRMATION } from './confirmation.js' +import { LAND_GRANTS } from './land-grants.js' +import { WOODLAND } from './woodland.js' +import { AGREEMENTS } from './agreements.js' +import { COOKIES } from './cookies.js' +import { RESOURCE_NOT_FOUND } from './resource-not-found.js' +import { APPLICATION_LOCKS } from './application-locks.js' +import { PRINT_APPLICATION } from './print-application.js' +import { SYSTEM } from './system.js' + +/** + * @namespace LogTypes + * @typedef {"info"|"warn"|"error"|"debug"} LogTypes.LogLevel + * + * @typedef {Object} LogCodesDefinition + * @property {LogTypes.LogLevel} level - The log level (e.g., 'info', 'warn', 'error', 'debug'). + * @property {(messageOptions: Record) => string} messageFunc - A function that takes message options. Each log code reads its own per-call fields, so the bag is intentionally loose; tightening to `unknown` breaks legitimate per-code field access (e.g. `.missingFields.join()`, `new URL(...)`). + */ + +/** + * @type {Record>} + */ +export const LogCodes = { + AUTH, + FORMS, + SUBMISSION, + DECLARATION, + CONFIRMATION, + LAND_GRANTS, + WOODLAND, + AGREEMENTS, + COOKIES, + RESOURCE_NOT_FOUND, + APPLICATION_LOCKS, + PRINT_APPLICATION, + SYSTEM +} diff --git a/src/server/common/helpers/logging/log-codes/forms.js b/src/server/common/helpers/logging/log-codes/forms.js new file mode 100644 index 000000000..8cea0a288 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/forms.js @@ -0,0 +1,42 @@ +/** + * @type {Object} + */ +export const FORMS = { + FORM_LOAD: { + level: 'info', + messageFunc: (messageOptions) => + `Form loaded: ${messageOptions.formName} for user=${messageOptions.userId || 'unknown'}` + }, + FORM_SUBMIT: { + level: 'info', + messageFunc: (messageOptions) => + `Form submitted: ${messageOptions.formName} by user=${messageOptions.userId || 'unknown'}` + }, + FORM_VALIDATION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Form validation error in ${messageOptions.formName}: ${messageOptions.errorMessage}` + }, + FORM_VALIDATION_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => `Form validation successful for ${messageOptions.formName}` + }, + FORM_PROCESSING_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Form processing error for ${messageOptions.formName}: ${messageOptions.errorMessage}` + }, + FORM_SAVE: { + level: 'info', + messageFunc: (messageOptions) => + `Form saved: ${messageOptions.formName} for user=${messageOptions.userId || 'unknown'}` + }, + SLUG_STORED: { + level: 'debug', + messageFunc: (messageOptions) => `${messageOptions.controller}: Storing slug in context: ${messageOptions.slug}` + }, + SLUG_RESOLVED: { + level: 'debug', + messageFunc: (messageOptions) => `${messageOptions.controller}: ${messageOptions.message}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/land-grants.js b/src/server/common/helpers/logging/log-codes/land-grants.js new file mode 100644 index 000000000..e9ccd94f4 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/land-grants.js @@ -0,0 +1,53 @@ +/** + * @type {Object} + */ +export const LAND_GRANTS = { + LAND_GRANT_APPLICATION_STARTED: { + level: 'info', + messageFunc: (messageOptions) => `Land grant application started for user=${messageOptions.userId}` + }, + LAND_GRANT_APPLICATION_SUBMITTED: { + level: 'info', + messageFunc: (messageOptions) => + `Land grant application submitted for user=${messageOptions.userId}, referenceNumber=${messageOptions.referenceNumber}` + }, + LAND_GRANT_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Land grant processing error for user=${messageOptions.userId}: ${messageOptions.errorMessage}` + }, + NO_LAND_PARCELS_FOUND: { + level: 'warn', + messageFunc: (messageOptions) => `No land parcels found for sbi=${messageOptions.sbi}` + }, + NO_ACTIONS_FOUND: { + level: 'error', + messageFunc: (messageOptions) => + `No actions found | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` + }, + VALIDATE_APPLICATION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Error validating application: ${messageOptions.errorMessage} | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` + }, + FETCH_ACTIONS_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Error fetching actions: ${messageOptions.errorMessage} | sbi: ${messageOptions.sbi} | parcelId: ${messageOptions.parcelId} | sheetId: ${messageOptions.sheetId}` + }, + FARM_DETAILS_MISSING_FIELDS: { + level: 'warn', + messageFunc: (messageOptions) => + `Missing farm contact details for sbi: ${messageOptions.sbi} | fields: ${messageOptions.missingFields.join(', ')}` + }, + UNAUTHORISED_PARCEL: { + level: 'error', + messageFunc: (messageOptions) => + `Land parcel doesn't belong to sbi=${messageOptions.sbi} | selectedLandParcel: ${messageOptions.selectedLandParcel} | landParcelsForSbi=${JSON.stringify(messageOptions.landParcelsForSbi)}` + }, + API_REQUEST: { + level: 'info', + messageFunc: (messageOptions) => + `Land Grants API request | endpoint: ${messageOptions.endpoint} | url: ${messageOptions.url}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/print-application.js b/src/server/common/helpers/logging/log-codes/print-application.js new file mode 100644 index 000000000..17726fe3b --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/print-application.js @@ -0,0 +1,14 @@ +/** + * @type {Object} + */ +export const PRINT_APPLICATION = { + SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => `Print application viewed for referenceNumber=${messageOptions.referenceNumber}` + }, + ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Print application error for user=${messageOptions.userId}, slug=${messageOptions.slug}: ${messageOptions.errorMessage}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/resource-not-found.js b/src/server/common/helpers/logging/log-codes/resource-not-found.js new file mode 100644 index 000000000..c72ffd842 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/resource-not-found.js @@ -0,0 +1,15 @@ +/** + * @type {Object} + */ +export const RESOURCE_NOT_FOUND = { + FORM_NOT_FOUND: { + level: 'info', + messageFunc: (messageOptions) => + `Form not found: slug=${messageOptions.slug}, userId=${messageOptions.userId || 'anonymous'}, sbi=${messageOptions.sbi || 'unknown'}, reason=${messageOptions.reason || 'not_found'}, environment=${messageOptions.environment || 'unknown'}, referer=${messageOptions.referer || 'none'}` + }, + PAGE_NOT_FOUND: { + level: 'info', + messageFunc: (messageOptions) => + `Page not found: path=${messageOptions.path}, userId=${messageOptions.userId || 'anonymous'}, sbi=${messageOptions.sbi || 'unknown'}, referer=${messageOptions.referer || 'none'}, userAgent=${messageOptions.userAgent || 'unknown'}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/submission.js b/src/server/common/helpers/logging/log-codes/submission.js new file mode 100644 index 000000000..461a389c3 --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/submission.js @@ -0,0 +1,53 @@ +/** + * @type {Object} + */ +export const SUBMISSION = { + SUBMISSION_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => + `Grant submission successful for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}` + }, + SUBMISSION_COMPLETED: { + level: 'info', + messageFunc: (messageOptions) => + `Form submission completed for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}, fields=${messageOptions.numberOfFields || 0}, status=${messageOptions.status}` + }, + SUBMISSION_FAILURE: { + level: 'error', + messageFunc: (messageOptions) => + `Grant submission failed for grantType=${messageOptions.grantType}, userCrn=${messageOptions.userCrn}, userSbi=${messageOptions.userSbi}, error=${messageOptions.errorMessage}` + }, + SUBMISSION_VALIDATION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Submission validation error for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}, validationId=${messageOptions.validationId}` + }, + SUBMISSION_PAYLOAD_LOG: { + level: 'debug', + messageFunc: (messageOptions) => + `Submission payload for grantType=${messageOptions.grantType}:\n${JSON.stringify(messageOptions.payload, null, 2)}` + }, + SUBMISSION_REDIRECT_FAILURE: { + level: 'error', + messageFunc: (messageOptions) => + `Submission redirect failure for grantType=${messageOptions.grantType}, referenceNumber=${messageOptions.referenceNumber}. Error: ${messageOptions.errorMessage}` + }, + VALIDATOR_NOT_FOUND: { + level: 'error', + messageFunc: (messageOptions) => `No validator found for grantType=${messageOptions.grantType}` + }, + APPLICATION_STATUS_UPDATED: { + level: 'debug', + messageFunc: (messageOptions) => + `${messageOptions.controller}: Application status updated to ${messageOptions.status}` + }, + SUBMISSION_PROCESSING: { + level: 'debug', + messageFunc: (messageOptions) => + `${messageOptions.controller}: Processing form submission, path=${messageOptions.path}` + }, + SUBMISSION_REDIRECT: { + level: 'debug', + messageFunc: (messageOptions) => `${messageOptions.controller}: Redirecting to ${messageOptions.redirectPath}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/system.js b/src/server/common/helpers/logging/log-codes/system.js new file mode 100644 index 000000000..e32c837ba --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/system.js @@ -0,0 +1,167 @@ +/** + * @type {Object} + */ +export const SYSTEM = { + GENERIC_ERROR: { + level: 'error', + messageFunc: (messageOptions) => `An error occurred: ${messageOptions.errorMessage}` + }, + VIEW_DEBUG: { + level: 'debug', + messageFunc: (messageOptions) => + `View path debug: currentFile=${messageOptions.currentFilePath}, isBuilt=${messageOptions.isRunningBuiltCode}, basePath=${messageOptions.basePath}, workingDir=${messageOptions.processWorkingDir}, pathsResolved=${messageOptions.resolvedViewPaths?.length || 0}` + }, + VIEW_PATH_CHECK: { + level: 'debug', + messageFunc: (messageOptions) => + `View path ${messageOptions.index}: path=${messageOptions.path}, exists=${messageOptions.exists}, isAbsolute=${messageOptions.isAbsolute}` + }, + ENV_CONFIG_DEBUG: { + level: 'debug', + messageFunc: (messageOptions) => + `Environment configuration: ${messageOptions.configType} - ${JSON.stringify(messageOptions.configValues)}` + }, + SERVER_ERROR: { + level: 'error', + messageFunc: (messageOptions) => { + const suffix = + messageOptions.upstreamStatus !== undefined && messageOptions.upstreamStatus !== null + ? ` | upstreamStatus=${messageOptions.upstreamStatus}` + : '' + return `Server error occurred: ${messageOptions.errorMessage}${suffix}` + } + }, + STARTUP_PHASE: { + level: 'info', + messageFunc: (messageOptions) => `Startup phase: ${messageOptions.phase} - ${messageOptions.status}` + }, + PLUGIN_REGISTRATION: { + level: 'debug', + messageFunc: (messageOptions) => `Plugin registration: ${messageOptions.pluginName} - ${messageOptions.status}` + }, + SYSTEM_STARTUP: { + level: 'info', + messageFunc: (messageOptions) => `System startup completed on port=${messageOptions.port}` + }, + SYSTEM_SHUTDOWN: { + level: 'info', + messageFunc: () => 'System shutdown initiated' + }, + EXTERNAL_API_CALL: { + level: 'info', + messageFunc: (messageOptions) => + `External API call to ${messageOptions.endpoint} for user=${messageOptions.userId || 'unknown'}` + }, + EXTERNAL_API_CALL_DEBUG: { + level: 'debug', + messageFunc: (messageOptions) => + `External ${messageOptions.method} to ${new URL(messageOptions.endpoint).pathname} (${messageOptions.identity || 'unknown'})` + }, + EXTERNAL_API_ERROR: { + level: 'error', + messageFunc: (messageOptions) => { + const parts = [`External API error for ${messageOptions.endpoint}`] + if (messageOptions.service) { + parts.push(`service=${messageOptions.service}`) + } + if (messageOptions.upstreamStatus !== undefined && messageOptions.upstreamStatus !== null) { + parts.push(`upstreamStatus=${messageOptions.upstreamStatus}`) + } + if (messageOptions.attempts !== undefined && messageOptions.attempts !== null) { + parts.push(`attempts=${messageOptions.attempts}`) + } + return `${parts.join(' | ')}: ${messageOptions.errorMessage}` + } + }, + GAS_ACTION_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Error invoking GAS action ${messageOptions.action} for grant ${messageOptions.grantCode}: ${messageOptions.errorMessage}` + }, + BACKEND_AUTH_CONFIG_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `Backend auth configuration invalid | missingKeys=${messageOptions.missingKeys?.join(', ') || 'unknown'}` + }, + RELATIONSHIP_PARSE_ERROR: { + level: 'error', + messageFunc: (messageOptions) => + `extractFarmDetails: Invalid relationship format | relationships="${messageOptions.relationships}" | reason=${messageOptions.reason}` + }, + CONFIG_MISSING: { + level: 'error', + messageFunc: (messageOptions) => + `Missing required configuration: ${messageOptions?.missing?.join(', ') || 'unknown'}` + }, + CONFIG_INVALID: { + level: 'error', + messageFunc: (messageOptions) => + `Invalid configuration, key "${messageOptions.key}" is missing or invalid: ${messageOptions.value}` + }, + WHITELIST_CONFIG_INCOMPLETE: { + level: 'error', + messageFunc: (messageOptions) => + `Incomplete whitelist configuration in form "${messageOptions.formName}" | present=${messageOptions.presentVar} | missing=${messageOptions.missingVar}` + }, + CRN_ENV_VAR_MISSING: { + level: 'error', + messageFunc: (messageOptions) => + `CRN whitelist environment variable "${messageOptions.envVar}" missing for form "${messageOptions.formName}"` + }, + SBI_ENV_VAR_MISSING: { + level: 'error', + messageFunc: (messageOptions) => + `SBI whitelist environment variable "${messageOptions.envVar}" missing for form "${messageOptions.formName}"` + }, + INVALID_REDIRECT_RULES: { + level: 'error', + messageFunc: (messageOptions) => + `Invalid redirect rules in form "${messageOptions.formName}" | reason=${messageOptions.reason}` + }, + CONSOLIDATED_VIEW_API_ERROR: { + level: 'error', + messageFunc: (messageOptions) => { + const base = `Unexpected error fetching business data from Consolidated View API | sbi=${messageOptions.sbi || 'unknown'} | status=${messageOptions.statusCode || 'unknown'} | error=${messageOptions.errorMessage}` + return messageOptions.responseBody ? `${base} | responseBody=${messageOptions.responseBody}` : base + } + }, + CONSOLIDATED_VIEW_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => `Consolidated View API request successful | sbi=${messageOptions.sbi || 'unknown'}` + }, + CONSOLIDATED_VIEW_PARTIAL_SUCCESS: { + level: 'info', + messageFunc: (messageOptions) => + `Partial success from Consolidated View API | sbi=${messageOptions.sbi || 'unknown'} | failedPaths=${messageOptions.failedPaths} | status=${messageOptions.statusCode || 'unknown'}` + }, + CONSOLIDATED_VIEW_ADDRESS_FORMAT: { + level: 'info', + messageFunc: (messageOptions) => + `Address format for sbi=${messageOptions.sbi} is ${messageOptions.uprn ? 'structured' : 'unstructured'}, uprn=${messageOptions.uprn || 'not set'}` + }, + SESSION_STATE_CLEAR_FAILED: { + level: 'error', + messageFunc: (messageOptions) => + `Failed to clear application state for slug=${messageOptions.slug}, sessionKey=${messageOptions.sessionKey}, error=${messageOptions.errorMessage}` + }, + SESSION_STATE_KEY_PARSE_FAILED: { + level: 'error', + messageFunc: (messageOptions) => + `Failed to parse session key: error=${messageOptions.errorMessage}, path=${messageOptions.requestPath}` + }, + SESSION_STATE_FETCH_FAILED: { + level: 'error', + messageFunc: (messageOptions) => + `Failed to fetch saved state: sessionKey=${messageOptions.sessionKey}, error=${messageOptions.errorMessage}, path=${messageOptions.requestPath}` + }, + RATE_LIMIT_EXCEEDED: { + level: 'warn', + messageFunc: (messageOptions) => + `Rate limit exceeded: path=${messageOptions.path}, ip=${messageOptions.ip || 'unknown'}, userId=${messageOptions.userId || 'anonymous'}, userAgent=${messageOptions.userAgent || 'unknown'}` + }, + STATE_SIZE_EXCEEDED: { + level: 'warn', + messageFunc: (messageOptions) => + `State payload size ${messageOptions.size} bytes exceeds limit of ${messageOptions.limit} bytes for sessionKey=${messageOptions.sessionKey}` + } +} diff --git a/src/server/common/helpers/logging/log-codes/woodland.js b/src/server/common/helpers/logging/log-codes/woodland.js new file mode 100644 index 000000000..7cb63430b --- /dev/null +++ b/src/server/common/helpers/logging/log-codes/woodland.js @@ -0,0 +1,9 @@ +/** + * @type {Object} + */ +export const WOODLAND = { + VALIDATE_ERROR: { + level: 'error', + messageFunc: (messageOptions) => `Woodland validation error: ${messageOptions.errorMessage}` + } +} diff --git a/src/server/common/helpers/logging/log.js b/src/server/common/helpers/logging/log.js index afe075d5c..f59a15353 100644 --- a/src/server/common/helpers/logging/log.js +++ b/src/server/common/helpers/logging/log.js @@ -7,7 +7,7 @@ const logger = pino(loggerOptions) /** * Logs an event with the specified level and context. * @param {object} logCode - Logging options. - * @param {import('./log-codes-definition.js').LogTypes.LogLevel} logCode.level - The log level. + * @param {import('./log-codes/definition.js').LogTypes.LogLevel} logCode.level - The log level. * @param {Function} logCode.messageFunc - A function that creates an interpolated message string * @param {object} [logCode.error] - An error object (optional) * @param {object} messageOptions - Values for message interpolation @@ -22,7 +22,7 @@ const log = (logCode, messageOptions, request) => { /** * Logs an event with the specified level and context. * @param {object} logCode - Logging options. - * @param {import('./log-codes-definition.js').LogTypes.LogLevel} logCode.level - The log level. + * @param {import('./log-codes/definition.js').LogTypes.LogLevel} logCode.level - The log level. * @param {Function} logCode.messageFunc - A function that creates an interpolated message string * @param {object} [logCode.error] - An error object (optional) * @param {object} messageOptions - Values for message interpolation @@ -37,7 +37,7 @@ const debug = (logCode, messageOptions, request) => { /** * Returns the logger function corresponding to the given log level. - * @param {import('./log-codes-definition.js').LogTypes.LogLevel} level - The log level. + * @param {import('./log-codes/definition.js').LogTypes.LogLevel} level - The log level. * @param {object} [request] - Hapi request object (optional) * @returns {(errorContext: object | undefined, message: string) => void} Logger function. */ diff --git a/src/server/common/services/consolidated-view/consolidated-view.service.js b/src/server/common/services/consolidated-view/consolidated-view.service.js index acd80eed6..097e29298 100644 --- a/src/server/common/services/consolidated-view/consolidated-view.service.js +++ b/src/server/common/services/consolidated-view/consolidated-view.service.js @@ -2,7 +2,7 @@ import { config } from '~/src/config/config.js' import { getValidToken } from '~/src/server/common/helpers/entra/token-manager.js' import { escapeGraphQLString } from '~/src/server/common/helpers/graphql-utils.js' import { retry } from '~/src/server/common/helpers/retry.js' -import { log, debug, LogCodes } from '~/src/server/common/helpers/logging/log.js' +import { log, LogCodes } from '~/src/server/common/helpers/logging/log.js' import { ConsolidatedViewError } from '~/src/server/common/utils/errors/ConsolidatedViewError.js' import { statusCodes } from '../../constants/status-codes.js' @@ -149,14 +149,7 @@ async function fetchFromConsolidatedView(request, { query, formatResponse, toler return formatResponse(responseJson) } catch (error) { - debug( - LogCodes.SYSTEM.CONSOLIDATED_VIEW_API_ERROR, - { - sbi, - errorMessage: error.message - }, - request - ) + logConsolidatedViewUpstreamError(request, sbi, error) if (error instanceof ConsolidatedViewError) { throw error @@ -173,6 +166,18 @@ async function fetchFromConsolidatedView(request, { query, formatResponse, toler } } +function logConsolidatedViewUpstreamError(request, sbi, error) { + log( + LogCodes.SYSTEM.CONSOLIDATED_VIEW_API_ERROR, + { + sbi, + statusCode: error.status ?? error.statusCode ?? null, + errorMessage: error.message + }, + request + ) +} + async function makeStubRequest({ query, sbi, crn }) { const stubUrl = config.get('consolidatedView.stubUrl') diff --git a/src/server/common/services/consolidated-view/consolidated-view.service.test.js b/src/server/common/services/consolidated-view/consolidated-view.service.test.js index 9283e9f6e..7e27cc4a9 100644 --- a/src/server/common/services/consolidated-view/consolidated-view.service.test.js +++ b/src/server/common/services/consolidated-view/consolidated-view.service.test.js @@ -10,6 +10,7 @@ import { fetchBusinessAndCPH } from './consolidated-view.service.js' import { retry } from '~/src/server/common/helpers/retry.js' +import { log } from '~/src/server/common/helpers/logging/log.js' vi.mock('~/src/server/common/helpers/retry.js') @@ -256,6 +257,26 @@ describe('Consolidated View Service', () => { ) }) + it('should log CONSOLIDATED_VIEW_API_ERROR at error level on upstream failure', async () => { + mockFetchInstance.mockResolvedValueOnce({ + ok: false, + status: 500, + statusText: 'Internal Server Error', + text: () => Promise.resolve('Server error') + }) + + await expect(fetchBusinessAndCPH(mockRequest)).rejects.toThrow() + + expect(log).toHaveBeenCalledWith( + expect.objectContaining({ level: 'error' }), + expect.objectContaining({ + sbi: mockSbi, + errorMessage: expect.stringContaining('500') + }), + mockRequest + ) + }) + it('should use stub endpoint in mock mode', async () => { config.set('consolidatedView', { apiEndpoint: 'https://api.example.com/graphql', diff --git a/src/server/common/services/grant-application/grant-application.service.js b/src/server/common/services/grant-application/grant-application.service.js index cb6fc0cfd..0d13c94a4 100644 --- a/src/server/common/services/grant-application/grant-application.service.js +++ b/src/server/common/services/grant-application/grant-application.service.js @@ -1,5 +1,5 @@ import { config } from '~/src/config/config.js' -import { debug } from '~/src/server/common/helpers/logging/log.js' +import { log, LogCodes } from '~/src/server/common/helpers/logging/log.js' import { retry } from '~/src/server/common/helpers/retry.js' import { statusCodes } from '../../constants/status-codes.js' @@ -100,6 +100,19 @@ async function handleResponse(response, grantCode) { return response } +function logGasUpstreamError(request, url, error) { + log( + LogCodes.SYSTEM.EXTERNAL_API_ERROR, + { + endpoint: url, + service: 'grant-application-service', + upstreamStatus: error.status ?? null, + errorMessage: error.message + }, + request + ) +} + /** * Makes a request to the Grant Application Service (GAS) API * @param {string} url - API endpoint URL @@ -135,15 +148,7 @@ export async function makeGasApiRequest(url, grantCode, request, options = {}) { return response } catch (error) { - debug( - { - level: 'error', - error, - messageFunc: () => 'Unexpected error in GAS API request: ' + error.message - }, - {}, - request - ) + logGasUpstreamError(request, url, error) if (error instanceof GrantApplicationServiceApiError) { throw error } diff --git a/src/server/common/services/grant-application/grant-application.service.test.js b/src/server/common/services/grant-application/grant-application.service.test.js index da63610dd..4e405fcba 100644 --- a/src/server/common/services/grant-application/grant-application.service.test.js +++ b/src/server/common/services/grant-application/grant-application.service.test.js @@ -2,6 +2,7 @@ import { beforeEach, vi } from 'vitest' import { mockFetch, mockFetchWithResponse, mockSimpleRequest } from '~/src/__mocks__/hapi-mocks.js' import { config } from '~/src/config/config.js' import { retry } from '~/src/server/common/helpers/retry.js' +import { log } from '~/src/server/common/helpers/logging/log.js' let invokeGasGetAction let invokeGasPostAction @@ -249,6 +250,27 @@ describe('Grant Application service (token present)', () => { body: JSON.stringify(payload) }) }) + + test('should log EXTERNAL_API_ERROR with service and upstreamStatus on GAS 5xx', async () => { + const mockedFetch = mockFetch() + mockedFetch.mockResolvedValue({ + ok: false, + status: 502, + json: () => ({ message: 'Bad Gateway' }), + statusText: 'Bad Gateway' + }) + + await expect(invokeGasPostAction(code, actionName, payload)).rejects.toThrow() + + expect(log).toHaveBeenCalledWith( + expect.objectContaining({ level: 'error' }), + expect.objectContaining({ + service: 'grant-application-service', + upstreamStatus: 502 + }), + undefined + ) + }) }) describe('invokeGasGetAction', () => { diff --git a/src/server/common/utils/errors/BaseError.js b/src/server/common/utils/errors/BaseError.js index 0daad6d55..f8d69d294 100644 --- a/src/server/common/utils/errors/BaseError.js +++ b/src/server/common/utils/errors/BaseError.js @@ -1,7 +1,7 @@ /** * @typedef {typeof import('../../constants/status-codes.js').statusCodes} StatusCodes * @typedef {(StatusCodes)[keyof StatusCodes]} StatusCode - * @typedef {import('../../helpers/logging/log-codes-definition.js').LogCodesDefinition} LogDefinition + * @typedef {import('../../helpers/logging/log-codes/definition.js').LogCodesDefinition} LogDefinition * */ diff --git a/src/server/land-grants/services/land-grants.client.js b/src/server/land-grants/services/land-grants.client.js index d5f27fa50..c0deca437 100644 --- a/src/server/land-grants/services/land-grants.client.js +++ b/src/server/land-grants/services/land-grants.client.js @@ -3,11 +3,29 @@ import { log, LogCodes } from '~/src/server/common/helpers/logging/log.js' import { retry } from '~/src/server/common/helpers/retry.js' import { getConsentTypes } from '~/src/server/land-grants/utils/consent-types.js' +const LAND_GRANTS_SERVICE = 'grants-ui-backend' + +/** + * @param {string} endpoint + * @param {number | null | undefined} status + * @param {string} errorMessage + * @param {number} [attempts] + */ +function logUpstreamError(endpoint, status, errorMessage, attempts) { + log(LogCodes.SYSTEM.EXTERNAL_API_ERROR, { + endpoint, + service: LAND_GRANTS_SERVICE, + upstreamStatus: status, + ...(attempts === undefined ? {} : { attempts }), + errorMessage + }) +} + /** * Performs a POST request to the Land Grants API. * @template T * @param {string} endpoint - * @param {object} body + * @param {Record} body * @param {string} baseUrl * @returns {Promise} * @throws {Error} @@ -16,7 +34,12 @@ export async function postToLandGrantsApi(endpoint, body, baseUrl) { const url = `${baseUrl}${endpoint}` log(LogCodes.LAND_GRANTS.API_REQUEST, { endpoint, url }) + let attempts = 0 + /** @type {number | null} */ + let lastUpstreamStatus = null + const apiOperation = async () => { + attempts += 1 const response = await fetch(url, { method: 'POST', headers: /** @type {HeadersInit} */ (createApiHeadersForLandGrantsBackend()), @@ -25,6 +48,8 @@ export async function postToLandGrantsApi(endpoint, body, baseUrl) { if (!response.ok) { await response.arrayBuffer() + lastUpstreamStatus = response.status + logUpstreamError(endpoint, response.status, response.statusText) /** * @type {Error & {code?: number, status?: number}} */ @@ -37,10 +62,15 @@ export async function postToLandGrantsApi(endpoint, body, baseUrl) { return response.json() } - return retry(apiOperation, { + const result = await retry(apiOperation, { timeout: 30000, serviceName: `LandGrantsApi.postTo ${endpoint}` + }).catch((error) => { + logUpstreamError(endpoint, error.status ?? error.code ?? lastUpstreamStatus, error.message, attempts) + throw error }) + + return result } /** diff --git a/src/server/land-grants/services/land-grants.client.test.js b/src/server/land-grants/services/land-grants.client.test.js index bc93db583..f50a52f02 100644 --- a/src/server/land-grants/services/land-grants.client.test.js +++ b/src/server/land-grants/services/land-grants.client.test.js @@ -9,21 +9,10 @@ import { } from './land-grants.client.js' import { vi } from 'vitest' import { retry } from '~/src/server/common/helpers/retry.js' +import { log } from '~/src/server/common/helpers/logging/log.js' vi.mock('~/src/server/common/helpers/retry.js') -vi.mock('~/src/server/common/helpers/logging/log.js', () => ({ - log: vi.fn(), - LogCodes: { - LAND_GRANTS: { - API_REQUEST: { - level: 'info', - messageFunc: (opts) => `Land Grants API request | endpoint: ${opts.endpoint} | url: ${opts.url}` - } - } - } -})) - /** @type {import('vitest').MockedFunction} */ const mockFetch = vi.fn() @@ -224,10 +213,9 @@ describe('Land Grants client', () => { ) }) - it('should handle error with different status codes', async () => { - const statusCodes = [400, 401, 403, 500, 502, 503] - - for (const status of statusCodes) { + it.each([400, 401, 403, 500, 502, 503])( + 'propagates upstream status %i as both error.code and error.status', + async (status) => { mockFetch.mockResolvedValueOnce({ ok: false, status, @@ -235,14 +223,140 @@ describe('Land Grants client', () => { arrayBuffer: vi.fn().mockResolvedValue(undefined) }) - try { - await postToLandGrantsApi('/test', {}, mockApiEndpoint) - expect.fail('Should have thrown an error') - } catch (error) { - expect(error.status).toBe(status) - expect(error.code).toBe(status) - } + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toMatchObject({ + code: status, + status + }) } + ) + + it('should log EXTERNAL_API_ERROR with upstreamStatus and service when BE returns 502', async () => { + mockFetch.mockResolvedValueOnce({ + ok: false, + status: 502, + statusText: 'Bad Gateway', + arrayBuffer: vi.fn().mockResolvedValue(undefined) + }) + + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toThrow('Bad Gateway') + + // Call-site log: fired before the error is rethrown, capturing upstream status + expect(log).toHaveBeenCalledWith( + expect.objectContaining({ level: 'error' }), + expect.objectContaining({ + endpoint: '/test', + service: 'grants-ui-backend', + upstreamStatus: 502, + errorMessage: 'Bad Gateway' + }) + ) + }) + + it('should log EXTERNAL_API_ERROR with attempts after retry exhaustion', async () => { + // Make retry behave as if it tried multiple times before giving up. + retry.mockImplementationOnce(async (operation) => { + await operation().catch(() => {}) + await operation().catch(() => {}) + return operation() + }) + mockFetch.mockResolvedValue({ + ok: false, + status: 502, + statusText: 'Bad Gateway', + arrayBuffer: vi.fn().mockResolvedValue(undefined) + }) + + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toThrow('Bad Gateway') + + const exhaustionLogCall = log.mock.calls.find( + ([code, opts]) => code?.level === 'error' && opts?.attempts !== undefined + ) + expect(exhaustionLogCall).toBeDefined() + expect(exhaustionLogCall[1]).toEqual( + expect.objectContaining({ + endpoint: '/test', + service: 'grants-ui-backend', + upstreamStatus: 502, + attempts: 3, + errorMessage: 'Bad Gateway' + }) + ) + }) + + it('should fall back to lastUpstreamStatus when retry error has no status or code', async () => { + // Simulate a retry-level failure (e.g. timeout) where the rejected error has no status/code, + // but the inner operation already captured an upstream status via lastUpstreamStatus. + retry.mockImplementationOnce(async (operation) => { + await operation().catch(() => {}) + const timeoutError = new Error('Operation timed out') + throw timeoutError + }) + mockFetch.mockResolvedValueOnce({ + ok: false, + status: 502, + statusText: 'Bad Gateway', + arrayBuffer: vi.fn().mockResolvedValue(undefined) + }) + + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toThrow('Operation timed out') + + const exhaustionLogCall = log.mock.calls.find( + ([code, opts]) => code?.level === 'error' && opts?.errorMessage === 'Operation timed out' + ) + expect(exhaustionLogCall).toBeDefined() + expect(exhaustionLogCall[1]).toEqual( + expect.objectContaining({ + endpoint: '/test', + service: 'grants-ui-backend', + upstreamStatus: 502, + errorMessage: 'Operation timed out' + }) + ) + }) + + it('should pass null upstreamStatus when no upstream response was received', async () => { + // Network-level failure: fetch rejects before any HTTP response arrives. + retry.mockImplementationOnce(async () => { + throw new Error('Network down') + }) + + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toThrow('Network down') + + const exhaustionLogCall = log.mock.calls.find( + ([code, opts]) => code?.level === 'error' && opts?.errorMessage === 'Network down' + ) + expect(exhaustionLogCall).toBeDefined() + expect(exhaustionLogCall[1]).toEqual( + expect.objectContaining({ + endpoint: '/test', + service: 'grants-ui-backend', + upstreamStatus: null, + errorMessage: 'Network down' + }) + ) + }) + + it('should use error.code when error.status is missing', async () => { + retry.mockImplementationOnce(async () => { + const err = /** @type {Error & {code?: number}} */ (new Error('Forbidden')) + err.code = 403 + throw err + }) + + await expect(postToLandGrantsApi('/test', {}, mockApiEndpoint)).rejects.toThrow('Forbidden') + + const exhaustionLogCall = log.mock.calls.find( + ([code, opts]) => code?.level === 'error' && opts?.errorMessage === 'Forbidden' + ) + expect(exhaustionLogCall).toBeDefined() + expect(exhaustionLogCall[1]).toEqual( + expect.objectContaining({ + endpoint: '/test', + service: 'grants-ui-backend', + upstreamStatus: 403, + errorMessage: 'Forbidden' + }) + ) }) it('should return the exact response from json()', async () => { diff --git a/types/hapi-augmentations.d.ts b/types/hapi-augmentations.d.ts index 0c4b238d6..4fca2c669 100644 --- a/types/hapi-augmentations.d.ts +++ b/types/hapi-augmentations.d.ts @@ -4,4 +4,14 @@ declare module '@hapi/hapi' { interface ServerMethods { getFormService: () => object } + + // Mirrors @defra/forms-engine-plugin's augmentation, which our tsc can't + // resolve because the plugin's .d.ts uses path aliases (~/src/...). + interface RequestApplicationState { + model?: { + def?: { + metadata?: Record + } + } + } }