diff --git a/.github/actions/acceptance-tests/action.yaml b/.github/actions/acceptance-tests/action.yaml index 922232e..2ab024a 100644 --- a/.github/actions/acceptance-tests/action.yaml +++ b/.github/actions/acceptance-tests/action.yaml @@ -45,6 +45,14 @@ runs: echo "PR_NUMBER=${{ inputs.targetEnvironment }}" >> $GITHUB_ENV echo "ENVIRONMENT=${{ inputs.targetEnvironment }}" >> $GITHUB_ENV + - name: "Set TEST_MOCK_WEBHOOK_URL environment variable" + shell: bash + run: | + mock_webhook_url=$(jq -r '.mock_webhook_url.value // empty' terraform_output.json) + if [ -n "$mock_webhook_url" ]; then + echo "TEST_MOCK_WEBHOOK_URL=${mock_webhook_url}" >> $GITHUB_ENV + fi + - name: Run test - ${{ inputs.testType }} shell: bash env: diff --git a/.github/workflows/cicd-1-pull-request.yaml b/.github/workflows/cicd-1-pull-request.yaml index cd4d89e..4dcd5dc 100644 --- a/.github/workflows/cicd-1-pull-request.yaml +++ b/.github/workflows/cicd-1-pull-request.yaml @@ -171,7 +171,7 @@ jobs: --terraformAction "apply" \ --overrideProjectName "nhs" \ --overrideRoleName "nhs-main-acct-client-callbacks-github-deploy" \ - --overrides "branch_name=${GITHUB_HEAD_REF:-${GITHUB_REF#refs/heads/}}" + --overrides "branch_name=${GITHUB_HEAD_REF:-${GITHUB_REF#refs/heads/}},deploy_mock_webhook=true" acceptance-stage: # Recommended maximum execution time is 10 minutes name: "Acceptance stage" needs: [metadata, build-stage, pr-create-dynamic-environment] diff --git a/infrastructure/terraform/components/callbacks/README.md b/infrastructure/terraform/components/callbacks/README.md index 1c3f444..7447f33 100644 --- a/infrastructure/terraform/components/callbacks/README.md +++ b/infrastructure/terraform/components/callbacks/README.md @@ -42,6 +42,7 @@ | [client\_config\_bucket](#module\_client\_config\_bucket) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.28/terraform-s3bucket.zip | n/a | | [client\_destination](#module\_client\_destination) | ../../modules/client-destination | n/a | | [client\_transform\_filter\_lambda](#module\_client\_transform\_filter\_lambda) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.29/terraform-lambda.zip | n/a | +| [debug\_log\_bucket](#module\_debug\_log\_bucket) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.28/terraform-s3bucket.zip | n/a | | [kms](#module\_kms) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.29/terraform-kms.zip | n/a | | [mock\_webhook\_lambda](#module\_mock\_webhook\_lambda) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.29/terraform-lambda.zip | n/a | | [sqs\_inbound\_event](#module\_sqs\_inbound\_event) | https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.29/terraform-sqs.zip | n/a | @@ -49,6 +50,7 @@ | Name | Description | |------|-------------| +| [debug\_log\_bucket\_name](#output\_debug\_log\_bucket\_name) | S3 bucket name for debug logs (integration testing, deploy\_mock\_webhook=true only) | | [deployment](#output\_deployment) | Deployment details used for post-deployment scripts | | [mock\_webhook\_lambda\_log\_group\_name](#output\_mock\_webhook\_lambda\_log\_group\_name) | CloudWatch log group name for mock webhook lambda (for integration test queries) | | [mock\_webhook\_url](#output\_mock\_webhook\_url) | URL endpoint for mock webhook (for TEST\_WEBHOOK\_URL environment variable) | diff --git a/infrastructure/terraform/components/callbacks/cloudwatch_dashboard_dlq.tf b/infrastructure/terraform/components/callbacks/cloudwatch_dashboard_dlq.tf new file mode 100644 index 0000000..9a213a9 --- /dev/null +++ b/infrastructure/terraform/components/callbacks/cloudwatch_dashboard_dlq.tf @@ -0,0 +1,100 @@ +locals { + dlq_overview_metrics = [ + for client_key in sort(keys(local.all_clients)) : [ + "AWS/SQS", + "ApproximateNumberOfMessagesVisible", + "QueueName", + "${local.csi}-${client_key}-dlq-queue", + { "label" : "${client_key} DLQ" } + ] + ] + + dlq_timeseries_widgets = [ + for idx, client_key in sort(keys(local.all_clients)) : { + height = 6 + width = 12 + y = 5 + (floor(idx / 2) * 6) + x = (idx % 2) * 12 + type = "metric" + properties = { + title = "${client_key} DLQ Depth" + view = "timeSeries" + stacked = false + region = var.region + stat = "Maximum" + period = 300 + metrics = [ + [ + "AWS/SQS", + "ApproximateNumberOfMessagesVisible", + "QueueName", + "${local.csi}-${client_key}-dlq-queue", + { "label" : "Messages awaiting redrive", "color" : "#d62728" } + ], + [ + "AWS/SQS", + "NumberOfMessagesMoved", + "QueueName", + "${local.csi}-${client_key}-dlq-queue", + { "label" : "Messages being redriven", "color" : "#2ca02c" } + ] + ] + annotations = { + horizontal = [ + { + label = "Alarm threshold" + value = 0 + fill = "above" + } + ] + } + yAxis = { + left = { + min = 0 + showUnits = false + label = "Message count" + } + } + } + } + ] +} + +resource "aws_cloudwatch_dashboard" "dlq" { + dashboard_name = "${local.csi}-dlq" + + dashboard_body = jsonencode({ + widgets = concat( + [ + { + height = 1 + width = 24 + y = 0 + x = 0 + type = "text" + properties = { + markdown = "## DLQ Monitoring\nMessages in a DLQ indicate failed callback deliveries." + } + }, + { + height = 4 + width = 24 + y = 1 + x = 0 + type = "metric" + properties = { + title = "DLQ Depth Overview" + view = "singleValue" + sparkline = true + region = var.region + stat = "Maximum" + period = 300 + singleValueFullPrecision = false + metrics = local.dlq_overview_metrics + } + } + ], + local.dlq_timeseries_widgets, + ) + }) +} diff --git a/infrastructure/terraform/components/callbacks/cloudwatch_metric_alarm_dlq_depth.tf b/infrastructure/terraform/components/callbacks/cloudwatch_metric_alarm_dlq_depth.tf new file mode 100644 index 0000000..c38fb58 --- /dev/null +++ b/infrastructure/terraform/components/callbacks/cloudwatch_metric_alarm_dlq_depth.tf @@ -0,0 +1,31 @@ +resource "aws_cloudwatch_metric_alarm" "client_dlq_depth" { + for_each = toset(keys(local.all_clients)) + + alarm_name = "${local.csi}-${each.key}-dlq-depth" + alarm_description = join(" ", [ + "RELIABILITY: Messages are in DLQ for ${each.key}.", + "Failed callback deliveries require operator attention.", + ]) + + comparison_operator = "GreaterThanThreshold" + evaluation_periods = 1 + metric_name = "ApproximateNumberOfMessagesVisible" + namespace = "AWS/SQS" + period = 300 + statistic = "Sum" + threshold = 0 + actions_enabled = true + treat_missing_data = "notBreaching" + + dimensions = { + QueueName = "${local.csi}-${each.key}-dlq-queue" + } + + tags = merge( + local.default_tags, + { + Name = "${local.csi}-${each.key}-dlq-depth" + Client = each.key + }, + ) +} diff --git a/infrastructure/terraform/components/callbacks/module_mock_webhook_lambda.tf b/infrastructure/terraform/components/callbacks/module_mock_webhook_lambda.tf index ab1683e..7431605 100644 --- a/infrastructure/terraform/components/callbacks/module_mock_webhook_lambda.tf +++ b/infrastructure/terraform/components/callbacks/module_mock_webhook_lambda.tf @@ -36,8 +36,9 @@ module "mock_webhook_lambda" { log_subscription_role_arn = local.acct.log_subscription_role_arn lambda_env_vars = { - LOG_LEVEL = var.log_level - API_KEY = random_password.mock_webhook_api_key[0].result + LOG_LEVEL = var.log_level + API_KEY = random_password.mock_webhook_api_key[0].result + DEBUG_BUCKET_NAME = module.debug_log_bucket[0].id } } @@ -63,6 +64,19 @@ data "aws_iam_policy_document" "mock_webhook_lambda" { module.kms.key_arn, ] } + + statement { + sid = "DebugLogBucketWrite" + effect = "Allow" + + actions = [ + "s3:PutObject", + ] + + resources = [ + "${module.debug_log_bucket[0].arn}/*", + ] + } } # Lambda Function URL for mock webhook (test/dev only) diff --git a/infrastructure/terraform/components/callbacks/module_transform_filter_lambda.tf b/infrastructure/terraform/components/callbacks/module_transform_filter_lambda.tf index 386e237..d5cc22b 100644 --- a/infrastructure/terraform/components/callbacks/module_transform_filter_lambda.tf +++ b/infrastructure/terraform/components/callbacks/module_transform_filter_lambda.tf @@ -36,7 +36,8 @@ module "client_transform_filter_lambda" { lambda_env_vars = { ENVIRONMENT = var.environment - METRICS_NAMESPACE = "nhs-notify-client-callbacks-metrics" + METRICS_NAMESPACE = "nhs-notify-client-callbacks" + DEBUG_BUCKET_NAME = var.deploy_mock_webhook ? module.debug_log_bucket[0].id : "" CLIENT_SUBSCRIPTION_CONFIG_BUCKET = module.client_config_bucket.id CLIENT_SUBSCRIPTION_CONFIG_PREFIX = "client_subscriptions/" CLIENT_SUBSCRIPTION_CACHE_TTL_SECONDS = "60" @@ -83,4 +84,21 @@ data "aws_iam_policy_document" "client_transform_filter_lambda" { "*", ] } + + dynamic "statement" { + for_each = var.deploy_mock_webhook ? toset(["enabled"]) : toset([]) + + content { + sid = "DebugLogBucketWrite" + effect = "Allow" + + actions = [ + "s3:PutObject", + ] + + resources = [ + "${module.debug_log_bucket[0].arn}/*", + ] + } + } } diff --git a/infrastructure/terraform/components/callbacks/outputs.tf b/infrastructure/terraform/components/callbacks/outputs.tf index b042e36..68cc413 100644 --- a/infrastructure/terraform/components/callbacks/outputs.tf +++ b/infrastructure/terraform/components/callbacks/outputs.tf @@ -15,7 +15,7 @@ output "deployment" { } ## -# Mock Webhook Lambda Outputs (test/dev environments only) +# Mock Webhook Lambda Outputs (test/dev environments only). ## output "mock_webhook_lambda_log_group_name" { @@ -27,3 +27,8 @@ output "mock_webhook_url" { description = "URL endpoint for mock webhook (for TEST_WEBHOOK_URL environment variable)" value = var.deploy_mock_webhook ? aws_lambda_function_url.mock_webhook[0].function_url : null } + +output "debug_log_bucket_name" { + description = "S3 bucket name for debug logs (integration testing, deploy_mock_webhook=true only)" + value = var.deploy_mock_webhook ? module.debug_log_bucket[0].id : null +} diff --git a/infrastructure/terraform/components/callbacks/s3_bucket_debug_log.tf b/infrastructure/terraform/components/callbacks/s3_bucket_debug_log.tf new file mode 100644 index 0000000..efc366d --- /dev/null +++ b/infrastructure/terraform/components/callbacks/s3_bucket_debug_log.tf @@ -0,0 +1,93 @@ +module "debug_log_bucket" { + count = var.deploy_mock_webhook ? 1 : 0 + source = "https://github.com/NHSDigital/nhs-notify-shared-modules/releases/download/v2.0.28/terraform-s3bucket.zip" + + name = "debug-log" + + aws_account_id = var.aws_account_id + component = var.component + environment = var.environment + project = var.project + region = var.region + + default_tags = merge( + local.default_tags, + { + Description = "Debug log storage for integration testing" + } + ) + + kms_key_arn = module.kms.key_arn + force_destroy = true + versioning = false + object_ownership = "BucketOwnerPreferred" + bucket_key_enabled = true + + policy_documents = [ + data.aws_iam_policy_document.debug_log_bucket[0].json, + ] +} + +data "aws_iam_policy_document" "debug_log_bucket" { + count = var.deploy_mock_webhook ? 1 : 0 + + statement { + sid = "AllowLambdaWriteAccess" + effect = "Allow" + + principals { + type = "AWS" + identifiers = [ + module.mock_webhook_lambda[0].iam_role_arn, + module.client_transform_filter_lambda.iam_role_arn, + ] + } + + actions = [ + "s3:PutObject", + ] + + resources = [ + "${module.debug_log_bucket[0].arn}/*", + ] + } + + statement { + sid = "DenyInsecureTransport" + effect = "Deny" + + principals { + type = "*" + identifiers = ["*"] + } + + actions = [ + "s3:*", + ] + + resources = [ + module.debug_log_bucket[0].arn, + "${module.debug_log_bucket[0].arn}/*", + ] + + condition { + test = "Bool" + variable = "aws:SecureTransport" + values = ["false"] + } + } +} + +resource "aws_s3_bucket_lifecycle_configuration" "debug_log" { + count = var.deploy_mock_webhook ? 1 : 0 + bucket = module.debug_log_bucket[0].id + + rule { + id = "expire-debug-logs" + status = "Enabled" + + expiration { + days = 1 + } + } +} diff --git a/jest.config.base.ts b/jest.config.base.ts index f057e3e..52c1d02 100644 --- a/jest.config.base.ts +++ b/jest.config.base.ts @@ -5,7 +5,7 @@ export const baseJestConfig: Config = { clearMocks: true, collectCoverage: true, coverageDirectory: "./.reports/unit/coverage", - coverageProvider: "v8", + coverageProvider: "babel", coveragePathIgnorePatterns: ["/__tests__/", "/node_modules/"], transform: { "^.+\\.ts$": "ts-jest" }, testPathIgnorePatterns: [".build"], diff --git a/lambdas/client-transform-filter-lambda/package.json b/lambdas/client-transform-filter-lambda/package.json index 4a4be91..82cd8dc 100644 --- a/lambdas/client-transform-filter-lambda/package.json +++ b/lambdas/client-transform-filter-lambda/package.json @@ -1,12 +1,12 @@ { "dependencies": { "@aws-sdk/client-s3": "^3.821.0", + "@nhs-notify-client-callbacks/logger": "*", "@nhs-notify-client-callbacks/models": "*", "aws-embedded-metrics": "^4.2.1", "cloudevents": "^8.0.2", "esbuild": "^0.25.0", "p-map": "^4.0.0", - "pino": "^9.6.0", "zod": "^4.1.13" }, "devDependencies": { diff --git a/lambdas/client-transform-filter-lambda/src/__tests__/index.test.ts b/lambdas/client-transform-filter-lambda/src/__tests__/index.test.ts index bda75a6..fc3317b 100644 --- a/lambdas/client-transform-filter-lambda/src/__tests__/index.test.ts +++ b/lambdas/client-transform-filter-lambda/src/__tests__/index.test.ts @@ -489,6 +489,8 @@ describe("createHandler default wiring", () => { jest.doMock("services/logger", () => ({ Logger: state.LoggerCtor, + + flushLogs: jest.fn().mockResolvedValue(undefined), })); jest.doMock("services/observability", () => ({ diff --git a/lambdas/client-transform-filter-lambda/src/index.ts b/lambdas/client-transform-filter-lambda/src/index.ts index 5ef8e19..87d4afd 100644 --- a/lambdas/client-transform-filter-lambda/src/index.ts +++ b/lambdas/client-transform-filter-lambda/src/index.ts @@ -1,5 +1,5 @@ import type { SQSRecord } from "aws-lambda"; -import { Logger } from "services/logger"; +import { Logger, flushLogs } from "services/logger"; import { CallbackMetrics, createMetricLogger } from "services/metrics"; import { ObservabilityService } from "services/observability"; import { ConfigLoaderService } from "services/config-loader-service"; @@ -36,7 +36,13 @@ export function createHandler( return async (event: SQSRecord[]): Promise => { const observability = createObservabilityService(); - return processEvents(event, observability, configLoader.getLoader()); + const result = await processEvents( + event, + observability, + configLoader.getLoader(), + ); + await flushLogs(); + return result; }; } diff --git a/lambdas/client-transform-filter-lambda/src/services/logger.ts b/lambdas/client-transform-filter-lambda/src/services/logger.ts index bc6e389..5c373b2 100644 --- a/lambdas/client-transform-filter-lambda/src/services/logger.ts +++ b/lambdas/client-transform-filter-lambda/src/services/logger.ts @@ -1,92 +1 @@ -import pino from "pino"; - -export interface LogContext { - correlationId?: string; - clientId?: string; - eventType?: string; - messageId?: string; - statusCode?: number; - error?: Error | string; - [key: string]: any; -} - -const basePinoLogger = pino( - { - level: process.env.LOG_LEVEL || "info", - formatters: { - level: (label: string) => { - return { level: label.toUpperCase() }; - }, - }, - timestamp: () => `,"timestamp":"${new Date().toISOString()}"`, - }, - pino.destination({ sync: true }), -); - -export class Logger { - private pinoLogger: pino.Logger; - - private context: LogContext = {}; - - constructor(initialContext?: LogContext) { - if (initialContext) { - this.context = { ...initialContext }; - this.pinoLogger = basePinoLogger.child(initialContext); - } else { - this.pinoLogger = basePinoLogger; - } - } - - addContext(context: LogContext): void { - this.context = { ...this.context, ...context }; - this.pinoLogger = basePinoLogger.child(this.context); - } - - clearContext(): void { - this.context = {}; - this.pinoLogger = basePinoLogger; - } - - child(context: LogContext): Logger { - const mergedContext = { ...this.context, ...context }; - return new Logger(mergedContext); - } - - info(message: string, additionalContext?: LogContext): void { - this.pinoLogger.info(additionalContext || {}, message); - } - - warn(message: string, additionalContext?: LogContext): void { - this.pinoLogger.warn(additionalContext || {}, message); - } - - error(message: string, additionalContext?: LogContext): void { - this.pinoLogger.error(additionalContext || {}, message); - } - - debug(message: string, additionalContext?: LogContext): void { - this.pinoLogger.debug(additionalContext || {}, message); - } -} - -export const logger = new Logger(); - -export function extractCorrelationId(event: unknown): string | undefined { - if (!event || typeof event !== "object" || !("id" in event)) return undefined; - return typeof event.id === "string" ? event.id : undefined; -} - -export function logLifecycleEvent( - eventLogger: Logger, - stage: - | "processing-started" - | "transformation-started" - | "transformation-completed" - | "filtering-started" - | "filtering-matched" - | "delivery-initiated" - | "batch-processing-completed", - context: LogContext, -): void { - eventLogger.info(`Callback lifecycle: ${stage}`, context); -} +export * from "@nhs-notify-client-callbacks/logger"; diff --git a/lambdas/mock-webhook-lambda/package.json b/lambdas/mock-webhook-lambda/package.json index 5a5e592..de4d6fe 100644 --- a/lambdas/mock-webhook-lambda/package.json +++ b/lambdas/mock-webhook-lambda/package.json @@ -1,8 +1,8 @@ { "dependencies": { + "@nhs-notify-client-callbacks/logger": "*", "@nhs-notify-client-callbacks/models": "*", - "esbuild": "^0.25.0", - "pino": "^9.5.0" + "esbuild": "^0.25.0" }, "devDependencies": { "@tsconfig/node22": "^22.0.2", diff --git a/lambdas/mock-webhook-lambda/src/__tests__/index.test.ts b/lambdas/mock-webhook-lambda/src/__tests__/index.test.ts index 85db51d..09114f5 100644 --- a/lambdas/mock-webhook-lambda/src/__tests__/index.test.ts +++ b/lambdas/mock-webhook-lambda/src/__tests__/index.test.ts @@ -3,16 +3,25 @@ import { handler } from "index"; const TEST_API_KEY = "test-api-key"; -jest.mock("pino", () => { - const info = jest.fn(); - const error = jest.fn(); - const mockPino = jest.fn(() => ({ info, error })); - Object.defineProperty(mockPino, "destination", { - value: jest.fn(() => ({})), - }); - return { __esModule: true, default: mockPino, info, error }; +jest.mock("@nhs-notify-client-callbacks/logger", () => { + const instance = { + info: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + debug: jest.fn(), + }; + return { + Logger: jest.fn().mockReturnValue(instance), + + flushLogs: jest.fn().mockResolvedValue(undefined), + instance, + }; }); +const mockLogger = jest.requireMock( + "@nhs-notify-client-callbacks/logger", +).instance; + const DEFAULT_HEADERS = { "x-api-key": TEST_API_KEY }; const createMockEvent = ( @@ -274,27 +283,21 @@ describe("Mock Webhook Lambda", () => { }; const event = createMockEvent(JSON.stringify(callback)); - await handler(event); - const logger = jest.requireMock("pino"); - const infoCalls = logger.info.mock.calls as unknown[][]; - - expect(logger).toBeDefined(); - - const callbackLog = infoCalls - .map(([payload]: unknown[]) => payload) - .find( - (payload: unknown) => - typeof payload === "object" && - payload !== null && - "msg" in payload && - payload.msg === - 'CALLBACK some-idempotency-key MessageStatus : {"type":"MessageStatus","attributes":{"messageId":"test-msg-789","messageStatus":"delivered"},"links":{"message":"some-message-link"},"meta":{"idempotencyKey":"some-idempotency-key"}}', - ); + const callbackCall = mockLogger.info.mock.calls.find( + ([message]: [string]) => + typeof message === "string" && message.startsWith("CALLBACK"), + ); - expect(callbackLog).toBeDefined(); - expect(callbackLog).toMatchObject({ + expect(callbackCall).toBeDefined(); + const [message, context] = callbackCall as [ + string, + Record, + ]; + expect(message).toContain("some-idempotency-key"); + expect(message).toContain("MessageStatus"); + expect(context).toMatchObject({ correlationId: "some-idempotency-key", messageType: "MessageStatus", }); diff --git a/lambdas/mock-webhook-lambda/src/index.ts b/lambdas/mock-webhook-lambda/src/index.ts index 02220ff..5764f7f 100644 --- a/lambdas/mock-webhook-lambda/src/index.ts +++ b/lambdas/mock-webhook-lambda/src/index.ts @@ -1,13 +1,8 @@ import type { APIGatewayProxyEvent, APIGatewayProxyResult } from "aws-lambda"; -import pino from "pino"; +import { Logger, flushLogs } from "@nhs-notify-client-callbacks/logger"; import type { ClientCallbackPayload } from "@nhs-notify-client-callbacks/models"; -const logger = pino( - { - level: process.env.LOG_LEVEL || "info", - }, - pino.destination({ sync: true }), -); +const logger = new Logger(); function isClientCallbackPayload( value: unknown, @@ -38,13 +33,10 @@ function isClientCallbackPayload( }); } -export async function handler( +async function buildResponse( event: APIGatewayProxyEvent, ): Promise { - logger.info({ event }, "Received event"); - - logger.info({ - msg: "Mock webhook invoked", + logger.info("Mock webhook invoked", { path: event.path, method: event.httpMethod, }); @@ -53,7 +45,7 @@ export async function handler( const providedApiKey = event.headers["x-api-key"]; if (!expectedApiKey || providedApiKey !== expectedApiKey) { - logger.error({ msg: "Unauthorized: invalid or missing x-api-key" }); + logger.error("Unauthorized: invalid or missing x-api-key"); return { statusCode: 401, body: JSON.stringify({ message: "Unauthorized" }), @@ -61,9 +53,7 @@ export async function handler( } if (!event.body) { - logger.error({ - msg: "No event body received", - }); + logger.error("No event body received"); return { statusCode: 400, @@ -75,9 +65,7 @@ export async function handler( const parsed = JSON.parse(event.body) as unknown; if (!isClientCallbackPayload(parsed)) { - logger.error({ - msg: "Invalid message structure - missing or invalid data array", - }); + logger.error("Invalid message structure - missing or invalid data array"); return { statusCode: 400, @@ -86,8 +74,7 @@ export async function handler( } if (parsed.data.length !== 1) { - logger.error({ - msg: "Expected exactly 1 callback item in data array", + logger.error("Expected exactly 1 callback item in data array", { receivedCount: parsed.data.length, }); @@ -101,11 +88,13 @@ export async function handler( const [item] = parsed.data; const correlationId = item.meta.idempotencyKey; - logger.info({ - correlationId, - messageType: item.type, - msg: `CALLBACK ${correlationId} ${item.type} : ${JSON.stringify(item)}`, - }); + logger.info( + `CALLBACK ${correlationId} ${item.type} : ${JSON.stringify(item)}`, + { + correlationId, + messageType: item.type, + }, + ); return { statusCode: 200, @@ -113,10 +102,7 @@ export async function handler( }; } catch (error) { if (error instanceof SyntaxError) { - logger.error({ - error: error.message, - msg: "Invalid JSON body", - }); + logger.error("Invalid JSON body", { error: error.message }); return { statusCode: 400, @@ -124,9 +110,8 @@ export async function handler( }; } - logger.error({ + logger.error("Failed to process callback", { error: error instanceof Error ? error.message : String(error), - msg: "Failed to process callback", }); return { @@ -135,3 +120,11 @@ export async function handler( }; } } + +export async function handler( + event: APIGatewayProxyEvent, +): Promise { + const response = await buildResponse(event); + await flushLogs(); + return response; +} diff --git a/package-lock.json b/package-lock.json index 4bfd023..37b514b 100644 --- a/package-lock.json +++ b/package-lock.json @@ -7,6 +7,7 @@ "name": "nhs-notify-client-callbacks", "workspaces": [ "lambdas/client-transform-filter-lambda", + "src/logger", "src/models", "lambdas/mock-webhook-lambda", "tests/integration", @@ -50,12 +51,12 @@ "version": "0.0.1", "dependencies": { "@aws-sdk/client-s3": "^3.821.0", + "@nhs-notify-client-callbacks/logger": "*", "@nhs-notify-client-callbacks/models": "*", "aws-embedded-metrics": "^4.2.1", "cloudevents": "^8.0.2", "esbuild": "^0.25.0", "p-map": "^4.0.0", - "pino": "^9.6.0", "zod": "^4.1.13" }, "devDependencies": { @@ -84,9 +85,9 @@ "name": "nhs-notify-mock-webhook-lambda", "version": "0.0.1", "dependencies": { + "@nhs-notify-client-callbacks/logger": "*", "@nhs-notify-client-callbacks/models": "*", - "esbuild": "^0.25.0", - "pino": "^9.5.0" + "esbuild": "^0.25.0" }, "devDependencies": { "@tsconfig/node22": "^22.0.2", @@ -360,45 +361,45 @@ } }, "node_modules/@aws-sdk/client-cognito-identity": { - "version": "3.1004.0", - "resolved": "https://registry.npmjs.org/@aws-sdk/client-cognito-identity/-/client-cognito-identity-3.1004.0.tgz", - "integrity": "sha512-iRFVMN0Rlh9tjEuz1c6eQnv9EiYH0uxIvobsn5IvOjsM0PdfsKpGdRKiQIA/OgmpTPfuYyySwaRRtDFH9TMlQw==", + "version": "3.1005.0", + "resolved": "https://registry.npmjs.org/@aws-sdk/client-cognito-identity/-/client-cognito-identity-3.1005.0.tgz", + "integrity": "sha512-vYZCaQPvawj2W76UtQCu2VCV0vEQnHxL1MOKri4jICLSRiFPlHTosUuwJDzJIIrvTuFgR2DolbcBLRSCLBo/oQ==", "license": "Apache-2.0", "dependencies": { "@aws-crypto/sha256-browser": "5.2.0", "@aws-crypto/sha256-js": "5.2.0", - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/credential-provider-node": "^3.972.18", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/credential-provider-node": "^3.972.19", "@aws-sdk/middleware-host-header": "^3.972.7", "@aws-sdk/middleware-logger": "^3.972.7", "@aws-sdk/middleware-recursion-detection": "^3.972.7", - "@aws-sdk/middleware-user-agent": "^3.972.19", + "@aws-sdk/middleware-user-agent": "^3.972.20", "@aws-sdk/region-config-resolver": "^3.972.7", "@aws-sdk/types": "^3.973.5", "@aws-sdk/util-endpoints": "^3.996.4", "@aws-sdk/util-user-agent-browser": "^3.972.7", - "@aws-sdk/util-user-agent-node": "^3.973.4", + "@aws-sdk/util-user-agent-node": "^3.973.5", "@smithy/config-resolver": "^4.4.10", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/fetch-http-handler": "^5.3.13", "@smithy/hash-node": "^4.2.11", "@smithy/invalid-dependency": "^4.2.11", "@smithy/middleware-content-length": "^4.2.11", - "@smithy/middleware-endpoint": "^4.4.22", - "@smithy/middleware-retry": "^4.4.39", + "@smithy/middleware-endpoint": "^4.4.23", + "@smithy/middleware-retry": "^4.4.40", "@smithy/middleware-serde": "^4.2.12", "@smithy/middleware-stack": "^4.2.11", "@smithy/node-config-provider": "^4.3.11", "@smithy/node-http-handler": "^4.4.14", "@smithy/protocol-http": "^5.3.11", - "@smithy/smithy-client": "^4.12.2", + "@smithy/smithy-client": "^4.12.3", "@smithy/types": "^4.13.0", "@smithy/url-parser": "^4.2.11", "@smithy/util-base64": "^4.3.2", "@smithy/util-body-length-browser": "^4.2.2", "@smithy/util-body-length-node": "^4.2.3", - "@smithy/util-defaults-mode-browser": "^4.3.38", - "@smithy/util-defaults-mode-node": "^4.2.41", + "@smithy/util-defaults-mode-browser": "^4.3.39", + "@smithy/util-defaults-mode-node": "^4.2.42", "@smithy/util-endpoints": "^3.3.2", "@smithy/util-middleware": "^4.2.11", "@smithy/util-retry": "^4.2.11", @@ -703,19 +704,19 @@ } }, "node_modules/@aws-sdk/core": { - "version": "3.973.18", - "resolved": "https://registry.npmjs.org/@aws-sdk/core/-/core-3.973.18.tgz", - "integrity": "sha512-GUIlegfcK2LO1J2Y98sCJy63rQSiLiDOgVw7HiHPRqfI2vb3XozTVqemwO0VSGXp54ngCnAQz0Lf0YPCBINNxA==", + "version": "3.973.19", + "resolved": "https://registry.npmjs.org/@aws-sdk/core/-/core-3.973.19.tgz", + "integrity": "sha512-56KePyOcZnKTWCd89oJS1G6j3HZ9Kc+bh/8+EbvtaCCXdP6T7O7NzCiPuHRhFLWnzXIaXX3CxAz0nI5My9spHQ==", "license": "Apache-2.0", "dependencies": { "@aws-sdk/types": "^3.973.5", "@aws-sdk/xml-builder": "^3.972.10", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/node-config-provider": "^4.3.11", "@smithy/property-provider": "^4.2.11", "@smithy/protocol-http": "^5.3.11", "@smithy/signature-v4": "^5.3.11", - "@smithy/smithy-client": "^4.12.2", + "@smithy/smithy-client": "^4.12.3", "@smithy/types": "^4.13.0", "@smithy/util-base64": "^4.3.2", "@smithy/util-middleware": "^4.2.11", @@ -738,12 +739,12 @@ } }, "node_modules/@aws-sdk/credential-provider-cognito-identity": { - "version": "3.972.10", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-cognito-identity/-/credential-provider-cognito-identity-3.972.10.tgz", - "integrity": "sha512-R7saD8TvU6En8tFstAgbM9w6wlFxTwXrvMEpheVdGyDMKSxK412aRy87VNb2Mc2By0vL58OIE487afpxOc/rVQ==", + "version": "3.972.11", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-cognito-identity/-/credential-provider-cognito-identity-3.972.11.tgz", + "integrity": "sha512-yHBjinYauxSvikf15EtgXyZ9TBIMVHUSWFPycQtPltTINpK+uv6K22zKkVsbxpB0gvsdRdIWP0UG5gejM+jPuQ==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/nested-clients": "^3.996.7", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/types": "^4.13.0", @@ -754,12 +755,12 @@ } }, "node_modules/@aws-sdk/credential-provider-env": { - "version": "3.972.16", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-env/-/credential-provider-env-3.972.16.tgz", - "integrity": "sha512-HrdtnadvTGAQUr18sPzGlE5El3ICphnH6SU7UQOMOWFgRKbTRNN8msTxM4emzguUso9CzaHU2xy5ctSrmK5YNA==", + "version": "3.972.17", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-env/-/credential-provider-env-3.972.17.tgz", + "integrity": "sha512-MBAMW6YELzE1SdkOniqr51mrjapQUv8JXSGxtwRjQV0mwVDutVsn22OPAUt4RcLRvdiHQmNBDEFP9iTeSVCOlA==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", + "@aws-sdk/core": "^3.973.19", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/types": "^4.13.0", @@ -770,18 +771,18 @@ } }, "node_modules/@aws-sdk/credential-provider-http": { - "version": "3.972.18", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-http/-/credential-provider-http-3.972.18.tgz", - "integrity": "sha512-NyB6smuZAixND5jZumkpkunQ0voc4Mwgkd+SZ6cvAzIB7gK8HV8Zd4rS8Kn5MmoGgusyNfVGG+RLoYc4yFiw+A==", + "version": "3.972.19", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-http/-/credential-provider-http-3.972.19.tgz", + "integrity": "sha512-9EJROO8LXll5a7eUFqu48k6BChrtokbmgeMWmsH7lBb6lVbtjslUYz/ShLi+SHkYzTomiGBhmzTW7y+H4BxsnA==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", + "@aws-sdk/core": "^3.973.19", "@aws-sdk/types": "^3.973.5", "@smithy/fetch-http-handler": "^5.3.13", "@smithy/node-http-handler": "^4.4.14", "@smithy/property-provider": "^4.2.11", "@smithy/protocol-http": "^5.3.11", - "@smithy/smithy-client": "^4.12.2", + "@smithy/smithy-client": "^4.12.3", "@smithy/types": "^4.13.0", "@smithy/util-stream": "^4.5.17", "tslib": "^2.6.2" @@ -791,19 +792,19 @@ } }, "node_modules/@aws-sdk/credential-provider-ini": { - "version": "3.972.17", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-ini/-/credential-provider-ini-3.972.17.tgz", - "integrity": "sha512-dFqh7nfX43B8dO1aPQHOcjC0SnCJ83H3F+1LoCh3X1P7E7N09I+0/taID0asU6GCddfDExqnEvQtDdkuMe5tKQ==", - "license": "Apache-2.0", - "dependencies": { - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/credential-provider-env": "^3.972.16", - "@aws-sdk/credential-provider-http": "^3.972.18", - "@aws-sdk/credential-provider-login": "^3.972.17", - "@aws-sdk/credential-provider-process": "^3.972.16", - "@aws-sdk/credential-provider-sso": "^3.972.17", - "@aws-sdk/credential-provider-web-identity": "^3.972.17", - "@aws-sdk/nested-clients": "^3.996.7", + "version": "3.972.18", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-ini/-/credential-provider-ini-3.972.18.tgz", + "integrity": "sha512-vthIAXJISZnj2576HeyLBj4WTeX+I7PwWeRkbOa0mVX39K13SCGxCgOFuKj2ytm9qTlLOmXe4cdEnroteFtJfw==", + "license": "Apache-2.0", + "dependencies": { + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/credential-provider-env": "^3.972.17", + "@aws-sdk/credential-provider-http": "^3.972.19", + "@aws-sdk/credential-provider-login": "^3.972.18", + "@aws-sdk/credential-provider-process": "^3.972.17", + "@aws-sdk/credential-provider-sso": "^3.972.18", + "@aws-sdk/credential-provider-web-identity": "^3.972.18", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/credential-provider-imds": "^4.2.11", "@smithy/property-provider": "^4.2.11", @@ -816,13 +817,13 @@ } }, "node_modules/@aws-sdk/credential-provider-login": { - "version": "3.972.17", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-login/-/credential-provider-login-3.972.17.tgz", - "integrity": "sha512-gf2E5b7LpKb+JX2oQsRIDxdRZjBFZt2olCGlWCdb3vBERbXIPgm2t1R5mEnwd4j0UEO/Tbg5zN2KJbHXttJqwA==", + "version": "3.972.18", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-login/-/credential-provider-login-3.972.18.tgz", + "integrity": "sha512-kINzc5BBxdYBkPZ0/i1AMPMOk5b5QaFNbYMElVw5QTX13AKj6jcxnv/YNl9oW9mg+Y08ti19hh01HhyEAxsSJQ==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/nested-clients": "^3.996.7", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/protocol-http": "^5.3.11", @@ -835,17 +836,17 @@ } }, "node_modules/@aws-sdk/credential-provider-node": { - "version": "3.972.18", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-node/-/credential-provider-node-3.972.18.tgz", - "integrity": "sha512-ZDJa2gd1xiPg/nBDGhUlat02O8obaDEnICBAVS8qieZ0+nDfaB0Z3ec6gjZj27OqFTjnB/Q5a0GwQwb7rMVViw==", + "version": "3.972.19", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-node/-/credential-provider-node-3.972.19.tgz", + "integrity": "sha512-yDWQ9dFTr+IMxwanFe7+tbN5++q8psZBjlUwOiCXn1EzANoBgtqBwcpYcHaMGtn0Wlfj4NuXdf2JaEx1lz5RaQ==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/credential-provider-env": "^3.972.16", - "@aws-sdk/credential-provider-http": "^3.972.18", - "@aws-sdk/credential-provider-ini": "^3.972.17", - "@aws-sdk/credential-provider-process": "^3.972.16", - "@aws-sdk/credential-provider-sso": "^3.972.17", - "@aws-sdk/credential-provider-web-identity": "^3.972.17", + "@aws-sdk/credential-provider-env": "^3.972.17", + "@aws-sdk/credential-provider-http": "^3.972.19", + "@aws-sdk/credential-provider-ini": "^3.972.18", + "@aws-sdk/credential-provider-process": "^3.972.17", + "@aws-sdk/credential-provider-sso": "^3.972.18", + "@aws-sdk/credential-provider-web-identity": "^3.972.18", "@aws-sdk/types": "^3.973.5", "@smithy/credential-provider-imds": "^4.2.11", "@smithy/property-provider": "^4.2.11", @@ -858,12 +859,12 @@ } }, "node_modules/@aws-sdk/credential-provider-process": { - "version": "3.972.16", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-process/-/credential-provider-process-3.972.16.tgz", - "integrity": "sha512-n89ibATwnLEg0ZdZmUds5bq8AfBAdoYEDpqP3uzPLaRuGelsKlIvCYSNNvfgGLi8NaHPNNhs1HjJZYbqkW9b+g==", + "version": "3.972.17", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-process/-/credential-provider-process-3.972.17.tgz", + "integrity": "sha512-c8G8wT1axpJDgaP3xzcy+q8Y1fTi9A2eIQJvyhQ9xuXrUZhlCfXbC0vM9bM1CUXiZppFQ1p7g0tuUMvil/gCPg==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", + "@aws-sdk/core": "^3.973.19", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/shared-ini-file-loader": "^4.4.6", @@ -875,14 +876,14 @@ } }, "node_modules/@aws-sdk/credential-provider-sso": { - "version": "3.972.17", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-sso/-/credential-provider-sso-3.972.17.tgz", - "integrity": "sha512-wGtte+48xnhnhHMl/MsxzacBPs5A+7JJedjiP452IkHY7vsbYKcvQBqFye8LwdTJVeHtBHv+JFeTscnwepoWGg==", + "version": "3.972.18", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-sso/-/credential-provider-sso-3.972.18.tgz", + "integrity": "sha512-YHYEfj5S2aqInRt5ub8nDOX8vAxgMvd84wm2Y3WVNfFa/53vOv9T7WOAqXI25qjj3uEcV46xxfqdDQk04h5XQA==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/nested-clients": "^3.996.7", - "@aws-sdk/token-providers": "3.1004.0", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/nested-clients": "^3.996.8", + "@aws-sdk/token-providers": "3.1005.0", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/shared-ini-file-loader": "^4.4.6", @@ -894,13 +895,13 @@ } }, "node_modules/@aws-sdk/credential-provider-web-identity": { - "version": "3.972.17", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-web-identity/-/credential-provider-web-identity-3.972.17.tgz", - "integrity": "sha512-8aiVJh6fTdl8gcyL+sVNcNwTtWpmoFa1Sh7xlj6Z7L/cZ/tYMEBHq44wTYG8Kt0z/PpGNopD89nbj3FHl9QmTA==", + "version": "3.972.18", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-provider-web-identity/-/credential-provider-web-identity-3.972.18.tgz", + "integrity": "sha512-OqlEQpJ+J3T5B96qtC1zLLwkBloechP+fezKbCH0sbd2cCc0Ra55XpxWpk/hRj69xAOYtHvoC4orx6eTa4zU7g==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/nested-clients": "^3.996.7", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/shared-ini-file-loader": "^4.4.6", @@ -912,26 +913,26 @@ } }, "node_modules/@aws-sdk/credential-providers": { - "version": "3.1004.0", - "resolved": "https://registry.npmjs.org/@aws-sdk/credential-providers/-/credential-providers-3.1004.0.tgz", - "integrity": "sha512-THsua88i7DrPoO8WCIWLPWb8706s2ytl2ej+WB9sv39VPCJNc7YwGtTA51reziyzlLnJUGHkI+krp0oTHEGaBw==", - "license": "Apache-2.0", - "dependencies": { - "@aws-sdk/client-cognito-identity": "3.1004.0", - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/credential-provider-cognito-identity": "^3.972.10", - "@aws-sdk/credential-provider-env": "^3.972.16", - "@aws-sdk/credential-provider-http": "^3.972.18", - "@aws-sdk/credential-provider-ini": "^3.972.17", - "@aws-sdk/credential-provider-login": "^3.972.17", - "@aws-sdk/credential-provider-node": "^3.972.18", - "@aws-sdk/credential-provider-process": "^3.972.16", - "@aws-sdk/credential-provider-sso": "^3.972.17", - "@aws-sdk/credential-provider-web-identity": "^3.972.17", - "@aws-sdk/nested-clients": "^3.996.7", + "version": "3.1005.0", + "resolved": "https://registry.npmjs.org/@aws-sdk/credential-providers/-/credential-providers-3.1005.0.tgz", + "integrity": "sha512-H6Prb37+8TdTkGsYH1WkWjupWdM4aHTmF6VLdyTwOWmg4WFkKAb1OJcMrxNCJ8Yy/UvxOca4jk6z2ej+T1pjtQ==", + "license": "Apache-2.0", + "dependencies": { + "@aws-sdk/client-cognito-identity": "3.1005.0", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/credential-provider-cognito-identity": "^3.972.11", + "@aws-sdk/credential-provider-env": "^3.972.17", + "@aws-sdk/credential-provider-http": "^3.972.19", + "@aws-sdk/credential-provider-ini": "^3.972.18", + "@aws-sdk/credential-provider-login": "^3.972.18", + "@aws-sdk/credential-provider-node": "^3.972.19", + "@aws-sdk/credential-provider-process": "^3.972.17", + "@aws-sdk/credential-provider-sso": "^3.972.18", + "@aws-sdk/credential-provider-web-identity": "^3.972.18", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/config-resolver": "^4.4.10", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/credential-provider-imds": "^4.2.11", "@smithy/node-config-provider": "^4.3.11", "@smithy/property-provider": "^4.2.11", @@ -1105,15 +1106,15 @@ } }, "node_modules/@aws-sdk/middleware-user-agent": { - "version": "3.972.19", - "resolved": "https://registry.npmjs.org/@aws-sdk/middleware-user-agent/-/middleware-user-agent-3.972.19.tgz", - "integrity": "sha512-Km90fcXt3W/iqujHzuM6IaDkYCj73gsYufcuWXApWdzoTy6KGk8fnchAjePMARU0xegIR3K4N3yIo1vy7OVe8A==", + "version": "3.972.20", + "resolved": "https://registry.npmjs.org/@aws-sdk/middleware-user-agent/-/middleware-user-agent-3.972.20.tgz", + "integrity": "sha512-3kNTLtpUdeahxtnJRnj/oIdLAUdzTfr9N40KtxNhtdrq+Q1RPMdCJINRXq37m4t5+r3H70wgC3opW46OzFcZYA==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", + "@aws-sdk/core": "^3.973.19", "@aws-sdk/types": "^3.973.5", "@aws-sdk/util-endpoints": "^3.996.4", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/protocol-http": "^5.3.11", "@smithy/types": "^4.13.0", "@smithy/util-retry": "^4.2.11", @@ -1140,44 +1141,44 @@ } }, "node_modules/@aws-sdk/nested-clients": { - "version": "3.996.7", - "resolved": "https://registry.npmjs.org/@aws-sdk/nested-clients/-/nested-clients-3.996.7.tgz", - "integrity": "sha512-MlGWA8uPaOs5AiTZ5JLM4uuWDm9EEAnm9cqwvqQIc6kEgel/8s1BaOWm9QgUcfc9K8qd7KkC3n43yDbeXOA2tg==", + "version": "3.996.8", + "resolved": "https://registry.npmjs.org/@aws-sdk/nested-clients/-/nested-clients-3.996.8.tgz", + "integrity": "sha512-6HlLm8ciMW8VzfB80kfIx16PBA9lOa9Dl+dmCBi78JDhvGlx3I7Rorwi5PpVRkL31RprXnYna3yBf6UKkD/PqA==", "license": "Apache-2.0", "dependencies": { "@aws-crypto/sha256-browser": "5.2.0", "@aws-crypto/sha256-js": "5.2.0", - "@aws-sdk/core": "^3.973.18", + "@aws-sdk/core": "^3.973.19", "@aws-sdk/middleware-host-header": "^3.972.7", "@aws-sdk/middleware-logger": "^3.972.7", "@aws-sdk/middleware-recursion-detection": "^3.972.7", - "@aws-sdk/middleware-user-agent": "^3.972.19", + "@aws-sdk/middleware-user-agent": "^3.972.20", "@aws-sdk/region-config-resolver": "^3.972.7", "@aws-sdk/types": "^3.973.5", "@aws-sdk/util-endpoints": "^3.996.4", "@aws-sdk/util-user-agent-browser": "^3.972.7", - "@aws-sdk/util-user-agent-node": "^3.973.4", + "@aws-sdk/util-user-agent-node": "^3.973.5", "@smithy/config-resolver": "^4.4.10", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/fetch-http-handler": "^5.3.13", "@smithy/hash-node": "^4.2.11", "@smithy/invalid-dependency": "^4.2.11", "@smithy/middleware-content-length": "^4.2.11", - "@smithy/middleware-endpoint": "^4.4.22", - "@smithy/middleware-retry": "^4.4.39", + "@smithy/middleware-endpoint": "^4.4.23", + "@smithy/middleware-retry": "^4.4.40", "@smithy/middleware-serde": "^4.2.12", "@smithy/middleware-stack": "^4.2.11", "@smithy/node-config-provider": "^4.3.11", "@smithy/node-http-handler": "^4.4.14", "@smithy/protocol-http": "^5.3.11", - "@smithy/smithy-client": "^4.12.2", + "@smithy/smithy-client": "^4.12.3", "@smithy/types": "^4.13.0", "@smithy/url-parser": "^4.2.11", "@smithy/util-base64": "^4.3.2", "@smithy/util-body-length-browser": "^4.2.2", "@smithy/util-body-length-node": "^4.2.3", - "@smithy/util-defaults-mode-browser": "^4.3.38", - "@smithy/util-defaults-mode-node": "^4.2.41", + "@smithy/util-defaults-mode-browser": "^4.3.39", + "@smithy/util-defaults-mode-node": "^4.2.42", "@smithy/util-endpoints": "^3.3.2", "@smithy/util-middleware": "^4.2.11", "@smithy/util-retry": "^4.2.11", @@ -1238,13 +1239,13 @@ } }, "node_modules/@aws-sdk/token-providers": { - "version": "3.1004.0", - "resolved": "https://registry.npmjs.org/@aws-sdk/token-providers/-/token-providers-3.1004.0.tgz", - "integrity": "sha512-j9BwZZId9sFp+4GPhf6KrwO8Tben2sXibZA8D1vv2I1zBdvkUHcBA2g4pkqIpTRalMTLC0NPkBPX0gERxfy/iA==", + "version": "3.1005.0", + "resolved": "https://registry.npmjs.org/@aws-sdk/token-providers/-/token-providers-3.1005.0.tgz", + "integrity": "sha512-vMxd+ivKqSxU9bHx5vmAlFKDAkjGotFU56IOkDa5DaTu1WWwbcse0yFHEm9I537oVvodaiwMl3VBwgHfzQ2rvw==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/nested-clients": "^3.996.7", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/nested-clients": "^3.996.8", "@aws-sdk/types": "^3.973.5", "@smithy/property-provider": "^4.2.11", "@smithy/shared-ini-file-loader": "^4.4.6", @@ -1316,12 +1317,12 @@ } }, "node_modules/@aws-sdk/util-user-agent-node": { - "version": "3.973.4", - "resolved": "https://registry.npmjs.org/@aws-sdk/util-user-agent-node/-/util-user-agent-node-3.973.4.tgz", - "integrity": "sha512-uqKeLqZ9D3nQjH7HGIERNXK9qnSpUK08l4MlJ5/NZqSSdeJsVANYp437EM9sEzwU28c2xfj2V6qlkqzsgtKs6Q==", + "version": "3.973.5", + "resolved": "https://registry.npmjs.org/@aws-sdk/util-user-agent-node/-/util-user-agent-node-3.973.5.tgz", + "integrity": "sha512-Dyy38O4GeMk7UQ48RupfHif//gqnOPbq/zlvRssc11E2mClT+aUfc3VS2yD8oLtzqO3RsqQ9I3gOBB4/+HjPOw==", "license": "Apache-2.0", "dependencies": { - "@aws-sdk/middleware-user-agent": "^3.972.19", + "@aws-sdk/middleware-user-agent": "^3.972.20", "@aws-sdk/types": "^3.973.5", "@smithy/node-config-provider": "^4.3.11", "@smithy/types": "^4.13.0", @@ -2517,6 +2518,10 @@ "node": ">= 6" } }, + "node_modules/@nhs-notify-client-callbacks/logger": { + "resolved": "src/logger", + "link": true + }, "node_modules/@nhs-notify-client-callbacks/models": { "resolved": "src/models", "link": true @@ -4605,9 +4610,7 @@ } }, "node_modules/collect-v8-coverage": { - "version": "1.0.3", - "resolved": "https://registry.npmjs.org/collect-v8-coverage/-/collect-v8-coverage-1.0.3.tgz", - "integrity": "sha512-1L5aqIkwPfiodaMgQunkF1zRhNqifHBmtbbbxcr6yVxxBnliw4TDOW6NxpO8DJLgJ16OT+Y4ztZqP6p/FtXnAw==", + "version": "1.0.2", "dev": true, "license": "MIT" }, @@ -6249,16 +6252,19 @@ "license": "BSD-3-Clause" }, "node_modules/fast-xml-builder": { - "version": "1.0.0", - "resolved": "https://registry.npmjs.org/fast-xml-builder/-/fast-xml-builder-1.0.0.tgz", - "integrity": "sha512-fpZuDogrAgnyt9oDDz+5DBz0zgPdPZz6D4IR7iESxRXElrlGTRkHJ9eEt+SACRJwT0FNFrt71DFQIUFBJfX/uQ==", + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/fast-xml-builder/-/fast-xml-builder-1.1.0.tgz", + "integrity": "sha512-7mtITW/we2/wTUZqMyBOR2F8xP4CRxMiSEcQxPIqdRWdO2L/HZSOlzoNyghmyDwNB8BDxePooV1ZTJpkOUhdRg==", "funding": [ { "type": "github", "url": "https://github.com/sponsors/NaturalIntelligence" } ], - "license": "MIT" + "license": "MIT", + "dependencies": { + "path-expression-matcher": "^1.1.2" + } }, "node_modules/fast-xml-parser": { "version": "5.4.1", @@ -8774,6 +8780,21 @@ "node": ">=8" } }, + "node_modules/path-expression-matcher": { + "version": "1.1.2", + "resolved": "https://registry.npmjs.org/path-expression-matcher/-/path-expression-matcher-1.1.2.tgz", + "integrity": "sha512-LXWqJmcpp2BKOEmgt4CyuESFmBfPuhJlAHKJsFzuJU6CxErWk75BrO+Ni77M9OxHN6dCYKM4vj+21Z6cOL96YQ==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/NaturalIntelligence" + } + ], + "license": "MIT", + "engines": { + "node": ">=14.0.0" + } + }, "node_modules/path-is-absolute": { "version": "1.0.1", "dev": true, @@ -10902,6 +10923,21 @@ "url": "https://github.com/sponsors/colinhacks" } }, + "src/logger": { + "name": "@nhs-notify-client-callbacks/logger", + "version": "0.0.1", + "dependencies": { + "@aws-sdk/client-s3": "^3.821.0", + "pino": "^9.6.0" + }, + "devDependencies": { + "@tsconfig/node22": "^22.0.2", + "@types/jest": "^29.5.14", + "jest": "^29.7.0", + "ts-jest": "^29.4.6", + "typescript": "^5.8.2" + } + }, "src/models": { "name": "@nhs-notify-client-callbacks/models", "version": "0.0.1", @@ -10951,45 +10987,45 @@ } }, "tools/client-subscriptions-management/node_modules/@aws-sdk/client-sts": { - "version": "3.1004.0", - "resolved": "https://registry.npmjs.org/@aws-sdk/client-sts/-/client-sts-3.1004.0.tgz", - "integrity": "sha512-fxTiEmAwj91OtrmhafZtmxrUa4wfT1CmnnV45jZ3NCHSTJhZy0MrtNZShxSnuhbF0i/JfsZdst3oxQGzGcCCmw==", + "version": "3.1005.0", + "resolved": "https://registry.npmjs.org/@aws-sdk/client-sts/-/client-sts-3.1005.0.tgz", + "integrity": "sha512-TCCWkROc6akngO5595RBmD3Zeq9CFtoZa3TsugyvOoDEd0c/FFOnoAZ7TdTe3MLuvkbXH5yvN6hLyLQgytNIAg==", "license": "Apache-2.0", "dependencies": { "@aws-crypto/sha256-browser": "5.2.0", "@aws-crypto/sha256-js": "5.2.0", - "@aws-sdk/core": "^3.973.18", - "@aws-sdk/credential-provider-node": "^3.972.18", + "@aws-sdk/core": "^3.973.19", + "@aws-sdk/credential-provider-node": "^3.972.19", "@aws-sdk/middleware-host-header": "^3.972.7", "@aws-sdk/middleware-logger": "^3.972.7", "@aws-sdk/middleware-recursion-detection": "^3.972.7", - "@aws-sdk/middleware-user-agent": "^3.972.19", + "@aws-sdk/middleware-user-agent": "^3.972.20", "@aws-sdk/region-config-resolver": "^3.972.7", "@aws-sdk/types": "^3.973.5", "@aws-sdk/util-endpoints": "^3.996.4", "@aws-sdk/util-user-agent-browser": "^3.972.7", - "@aws-sdk/util-user-agent-node": "^3.973.4", + "@aws-sdk/util-user-agent-node": "^3.973.5", "@smithy/config-resolver": "^4.4.10", - "@smithy/core": "^3.23.8", + "@smithy/core": "^3.23.9", "@smithy/fetch-http-handler": "^5.3.13", "@smithy/hash-node": "^4.2.11", "@smithy/invalid-dependency": "^4.2.11", "@smithy/middleware-content-length": "^4.2.11", - "@smithy/middleware-endpoint": "^4.4.22", - "@smithy/middleware-retry": "^4.4.39", + "@smithy/middleware-endpoint": "^4.4.23", + "@smithy/middleware-retry": "^4.4.40", "@smithy/middleware-serde": "^4.2.12", "@smithy/middleware-stack": "^4.2.11", "@smithy/node-config-provider": "^4.3.11", "@smithy/node-http-handler": "^4.4.14", "@smithy/protocol-http": "^5.3.11", - "@smithy/smithy-client": "^4.12.2", + "@smithy/smithy-client": "^4.12.3", "@smithy/types": "^4.13.0", "@smithy/url-parser": "^4.2.11", "@smithy/util-base64": "^4.3.2", "@smithy/util-body-length-browser": "^4.2.2", "@smithy/util-body-length-node": "^4.2.3", - "@smithy/util-defaults-mode-browser": "^4.3.38", - "@smithy/util-defaults-mode-node": "^4.2.41", + "@smithy/util-defaults-mode-browser": "^4.3.39", + "@smithy/util-defaults-mode-node": "^4.2.42", "@smithy/util-endpoints": "^3.3.2", "@smithy/util-middleware": "^4.2.11", "@smithy/util-retry": "^4.2.11", @@ -11017,7 +11053,9 @@ } }, "tools/client-subscriptions-management/node_modules/@types/node": { - "version": "22.19.11", + "version": "22.19.15", + "resolved": "https://registry.npmjs.org/@types/node/-/node-22.19.15.tgz", + "integrity": "sha512-F0R/h2+dsy5wJAUe3tAU6oqa2qbWY5TpNfL/RGmo1y38hiyO1w3x2jPtt76wmuaJI4DQnOBu21cNXQ2STIUUWg==", "dev": true, "license": "MIT", "dependencies": { @@ -11026,6 +11064,8 @@ }, "tools/client-subscriptions-management/node_modules/undici-types": { "version": "6.21.0", + "resolved": "https://registry.npmjs.org/undici-types/-/undici-types-6.21.0.tgz", + "integrity": "sha512-iwDZqg0QAGrg9Rav5H4n0M64c3mkR59cJ6wQp+7C4nI0gsmExaedaYLNO44eT4AtBBwjbTiGPMlt2Md0T9H9JQ==", "dev": true, "license": "MIT" } diff --git a/package.json b/package.json index e254dc1..b54a122 100644 --- a/package.json +++ b/package.json @@ -54,6 +54,7 @@ }, "workspaces": [ "lambdas/client-transform-filter-lambda", + "src/logger", "src/models", "lambdas/mock-webhook-lambda", "tests/integration", diff --git a/scripts/config/sonar-scanner.properties b/scripts/config/sonar-scanner.properties index 6a2f270..71326c8 100644 --- a/scripts/config/sonar-scanner.properties +++ b/scripts/config/sonar-scanner.properties @@ -5,5 +5,5 @@ sonar.qualitygate.wait=true sonar.sourceEncoding=UTF-8 sonar.terraform.provider.aws.version=5.54.1 sonar.cpd.exclusions=**.test.*, src/models/** -sonar.coverage.exclusions=tests/**, lambdas/**/src/__tests__/**, src/models/**, scripts/**/src/__tests__/**, tools/**/src/__tests__/**, **/jest.config.* +sonar.coverage.exclusions=tests/**, lambdas/**/src/__tests__/**, src/**/src/__tests__/**, src/models/**, scripts/**/src/__tests__/**, tools/**/src/__tests__/**, **/jest.config.* sonar.javascript.lcov.reportPaths=lcov.info diff --git a/src/logger/jest.config.ts b/src/logger/jest.config.ts new file mode 100644 index 0000000..5a8709f --- /dev/null +++ b/src/logger/jest.config.ts @@ -0,0 +1,14 @@ +import { nodeJestConfig } from "../../jest.config.base"; + +export default { + ...nodeJestConfig, + coverageThreshold: { + global: { + ...nodeJestConfig.coverageThreshold?.global, + branches: 90, + functions: 75, + lines: 90, + statements: 90, + }, + }, +}; diff --git a/src/logger/package.json b/src/logger/package.json new file mode 100644 index 0000000..957e70e --- /dev/null +++ b/src/logger/package.json @@ -0,0 +1,28 @@ +{ + "name": "@nhs-notify-client-callbacks/logger", + "version": "0.0.1", + "private": true, + "exports": { + ".": { + "types": "./src/index.ts", + "default": "./src/index.ts" + } + }, + "dependencies": { + "@aws-sdk/client-s3": "^3.821.0", + "pino": "^9.6.0" + }, + "devDependencies": { + "@tsconfig/node22": "^22.0.2", + "@types/jest": "^29.5.14", + "jest": "^29.7.0", + "ts-jest": "^29.4.6", + "typescript": "^5.8.2" + }, + "scripts": { + "lint": "eslint .", + "lint:fix": "eslint . --fix", + "test:unit": "jest", + "typecheck": "tsc --noEmit" + } +} diff --git a/lambdas/client-transform-filter-lambda/src/__tests__/services/logger.test.ts b/src/logger/src/__tests__/index.test.ts similarity index 62% rename from lambdas/client-transform-filter-lambda/src/__tests__/services/logger.test.ts rename to src/logger/src/__tests__/index.test.ts index 94f1f47..cc1dfb5 100644 --- a/lambdas/client-transform-filter-lambda/src/__tests__/services/logger.test.ts +++ b/src/logger/src/__tests__/index.test.ts @@ -3,9 +3,10 @@ import { LogContext, Logger, extractCorrelationId, + flushLogs, logLifecycleEvent, logger, -} from "services/logger"; +} from ".."; jest.mock("pino", () => { const info = jest.fn(); @@ -28,7 +29,14 @@ jest.mock("pino", () => { }; }); -const mockLoggerMethods = pino() as any; +const mockSend = jest.fn().mockResolvedValue({}); + +jest.mock("@aws-sdk/client-s3", () => ({ + S3Client: jest.fn(() => ({ send: mockSend })), + PutObjectCommand: jest.fn((input) => ({ ...input })), +})); + +const mockLoggerMethods = pino() as jest.Mocked>; describe("Logger", () => { beforeEach(() => { @@ -58,9 +66,7 @@ describe("Logger", () => { describe("addContext", () => { it("should add new context to logger", () => { const testLogger = new Logger(); - const newContext: LogContext = { - correlationId: "corr-789", - }; + const newContext: LogContext = { correlationId: "corr-789" }; testLogger.addContext(newContext); @@ -73,37 +79,25 @@ describe("Logger", () => { clientId: "client-456", }; const testLogger = new Logger(initialContext); - mockLoggerMethods.child.mockClear(); - const additionalContext: LogContext = { - messageId: "msg-101", - }; - - testLogger.addContext(additionalContext); + testLogger.addContext({ messageId: "msg-101" }); expect(mockLoggerMethods.child).toHaveBeenCalledWith({ correlationId: "corr-123", clientId: "client-456", - messageId: "msg-101", }); }); it("should override existing context keys", () => { - const initialContext: LogContext = { + const testLogger = new Logger({ correlationId: "old-corr", clientId: "client-123", - }; - const testLogger = new Logger(initialContext); - + }); mockLoggerMethods.child.mockClear(); - const newContext: LogContext = { - correlationId: "new-corr", - }; - - testLogger.addContext(newContext); + testLogger.addContext({ correlationId: "new-corr" }); expect(mockLoggerMethods.child).toHaveBeenCalledWith({ correlationId: "new-corr", @@ -114,14 +108,8 @@ describe("Logger", () => { describe("clearContext", () => { it("should clear all context from logger", () => { - const initialContext: LogContext = { - correlationId: "corr-123", - clientId: "client-456", - }; - const testLogger = new Logger(initialContext); - + const testLogger = new Logger({ correlationId: "corr-123" }); testLogger.clearContext(); - expect(testLogger).toBeInstanceOf(Logger); }); }); @@ -129,36 +117,27 @@ describe("Logger", () => { describe("child", () => { it("should create a child logger with new context", () => { const testLogger = new Logger(); - const childContext: LogContext = { - correlationId: "corr-123", - }; - - const childLogger = testLogger.child(childContext); + const childLogger = testLogger.child({ correlationId: "corr-123" }); expect(childLogger).toBeInstanceOf(Logger); - expect(mockLoggerMethods.child).toHaveBeenCalledWith(childContext); + expect(mockLoggerMethods.child).toHaveBeenCalledWith({ + correlationId: "corr-123", + }); }); it("should merge parent context with child context", () => { - const parentContext: LogContext = { + const testLogger = new Logger({ correlationId: "parent-corr", clientId: "client-123", - }; - const testLogger = new Logger(parentContext); - + }); mockLoggerMethods.child.mockClear(); - const childContext: LogContext = { - messageId: "msg-101", - }; - - const childLogger = testLogger.child(childContext); + const childLogger = testLogger.child({ messageId: "msg-101" }); expect(childLogger).toBeInstanceOf(Logger); expect(mockLoggerMethods.child).toHaveBeenCalledWith({ correlationId: "parent-corr", clientId: "client-123", - messageId: "msg-101", }); }); @@ -225,10 +204,9 @@ describe("Logger", () => { it("should log error message with additional context", () => { const testLogger = new Logger(); - const error = new Error("Something failed"); const context: LogContext = { correlationId: "corr-789", - error, + error: new Error("fail"), }; testLogger.error("Operation failed", context); @@ -250,9 +228,7 @@ describe("Logger", () => { it("should log debug message with additional context", () => { const testLogger = new Logger(); - const context: LogContext = { - correlationId: "corr-101", - }; + const context: LogContext = { correlationId: "corr-101" }; testLogger.debug("Debug info", context); @@ -270,44 +246,125 @@ describe("Logger", () => { }); }); -describe("extractCorrelationId", () => { - it("should extract correlation ID from event.id", () => { - const event = { - id: "test-corr-123", - type: "status-update", - }; +describe("S3 debug bucket writes", () => { + beforeAll(() => { + process.env.DEBUG_BUCKET_NAME = "test-debug-bucket"; + }); - const correlationId = extractCorrelationId(event); + afterAll(() => { + delete process.env.DEBUG_BUCKET_NAME; + }); - expect(correlationId).toBe("test-corr-123"); + beforeEach(() => { + jest.clearAllMocks(); }); - it("should return undefined when id is not present", () => { - const event = { - type: "status-update", - }; + it("should write to S3 when DEBUG_BUCKET_NAME is set", () => { + const { PutObjectCommand } = jest.requireMock("@aws-sdk/client-s3"); + + const testLogger = new Logger(); + testLogger.info("Test message", { correlationId: "corr-123" }); + + expect(PutObjectCommand).toHaveBeenCalledWith( + expect.objectContaining({ + Bucket: "test-debug-bucket", + Key: expect.stringMatching(/^\d+-.+\.json$/), + ContentType: "application/json", + Body: expect.stringContaining('"message":"Test message"'), + }), + ); + expect(mockSend).toHaveBeenCalled(); + }); - const correlationId = extractCorrelationId(event); + it("should include context fields in S3 entry body", () => { + const { PutObjectCommand } = jest.requireMock("@aws-sdk/client-s3"); - expect(correlationId).toBeUndefined(); + const testLogger = new Logger(); + testLogger.error("Something failed", { + correlationId: "corr-xyz", + statusCode: 500, + }); + + const call = PutObjectCommand.mock.calls[0][0] as { Body: string }; + const entry = JSON.parse(call.Body) as Record; + + expect(entry).toMatchObject({ + level: "ERROR", + message: "Something failed", + correlationId: "corr-xyz", + statusCode: 500, + }); + expect(typeof entry.timestamp).toBe("string"); }); - it("should return undefined for null event", () => { - const correlationId = extractCorrelationId(null); + it("should write for warn and debug levels", () => { + const { PutObjectCommand } = jest.requireMock("@aws-sdk/client-s3"); + + const testLogger = new Logger(); + testLogger.warn("A warning"); + testLogger.debug("A debug"); + + expect(PutObjectCommand).toHaveBeenCalledTimes(2); + + const levels = PutObjectCommand.mock.calls.map( + (call: [{ Body: string }]) => { + const entry = JSON.parse(call[0].Body) as { + level: string; + }; + return entry.level; + }, + ); + expect(levels).toContain("WARN"); + expect(levels).toContain("DEBUG"); + }); - expect(correlationId).toBeUndefined(); + it("should not write to S3 when DEBUG_BUCKET_NAME is absent", () => { + const { PutObjectCommand } = jest.requireMock("@aws-sdk/client-s3"); + delete process.env.DEBUG_BUCKET_NAME; + + const testLogger = new Logger(); + testLogger.info("No bucket"); + + expect(PutObjectCommand).not.toHaveBeenCalled(); + + process.env.DEBUG_BUCKET_NAME = "test-debug-bucket"; }); - it("should return undefined for undefined event", () => { - const correlationId = extractCorrelationId(undefined as unknown); + it("flushLogs should resolve once all pending writes complete", async () => { + const testLogger = new Logger(); + testLogger.info("flush test"); + testLogger.warn("flush test 2"); - expect(correlationId).toBeUndefined(); + // Should resolve without throwing even if writes are in-flight + await expect(flushLogs()).resolves.toBeUndefined(); + }); +}); + +describe("extractCorrelationId", () => { + it("should extract correlation ID from event.id", () => { + expect( + extractCorrelationId({ id: "test-corr-123", type: "status-update" }), + ).toBe("test-corr-123"); + }); + + it("should return undefined when id is not present", () => { + expect(extractCorrelationId({ type: "status-update" })).toBeUndefined(); + }); + + it("should return undefined for null event", () => { + expect(extractCorrelationId(null)).toBeUndefined(); + }); + + it("should return undefined for undefined event", () => { + expect(extractCorrelationId(undefined as unknown)).toBeUndefined(); }); it("should return undefined for empty object", () => { - const correlationId = extractCorrelationId({}); + expect(extractCorrelationId({})).toBeUndefined(); + }); - expect(correlationId).toBeUndefined(); + it("should return undefined when id is not a string", () => { + expect(extractCorrelationId({ id: 42 })).toBeUndefined(); }); it("should return undefined when id is present but not a string", () => { @@ -337,7 +394,6 @@ describe("logLifecycleEvent", () => { "should log %s lifecycle event", (event) => { const testLogger = new Logger(); - logLifecycleEvent(testLogger, event, context); expect(mockLoggerMethods.info).toHaveBeenCalledWith( diff --git a/src/logger/src/index.ts b/src/logger/src/index.ts new file mode 100644 index 0000000..d22c4e0 --- /dev/null +++ b/src/logger/src/index.ts @@ -0,0 +1,168 @@ +import { PutObjectCommand, S3Client } from "@aws-sdk/client-s3"; +import pino from "pino"; + +export interface LogContext { + correlationId?: string; + clientId?: string; + eventType?: string; + messageId?: string; + statusCode?: number; + error?: Error | string; + + [key: string]: any; +} + +const basePinoLogger = pino( + { + level: process.env.LOG_LEVEL || "info", + formatters: { + level: (label: string) => { + return { level: label.toUpperCase() }; + }, + }, + timestamp: () => `,"timestamp":"${new Date().toISOString()}"`, + }, + pino.destination({ sync: true }), +); + +let s3Client: S3Client | undefined; +const pendingWrites = new Set>(); + +function getS3Client(): S3Client { + if (!s3Client) { + s3Client = new S3Client({}); + } + return s3Client; +} + +function writeToDebugBucket( + level: string, + message: string, + getContext: () => LogContext, +): void { + const bucketName = process.env.DEBUG_BUCKET_NAME; + if (!bucketName) return; + + const key = `${Date.now()}-${crypto.randomUUID()}.json`; + const body = JSON.stringify({ + level, + message, + timestamp: new Date().toISOString(), + ...getContext(), + }); + + const write = getS3Client() + .send( + new PutObjectCommand({ + Bucket: bucketName, + Key: key, + Body: body, + ContentType: "application/json", + }), + ) + .then(() => {}) + .catch((error: unknown) => { + basePinoLogger.error( + { error, key }, + "Failed to write debug log entry to S3", + ); + }) + .finally(() => { + pendingWrites.delete(write); + }); + + pendingWrites.add(write); +} + +/** + * Awaits all in-flight logging operations. Lambda handlers must call this before + * returning a response, otherwise the process may be frozen before the writes + * complete. + */ +export async function flushLogs(): Promise { + await Promise.allSettled(pendingWrites); +} + +export class Logger { + private pinoLogger: pino.Logger; + + private context: LogContext = {}; + + constructor(initialContext?: LogContext) { + if (initialContext) { + this.context = { ...initialContext }; + this.pinoLogger = basePinoLogger.child(initialContext); + } else { + this.pinoLogger = basePinoLogger; + } + } + + addContext(context: LogContext): void { + this.context = { ...this.context, ...context }; + this.pinoLogger = basePinoLogger.child(this.context); + } + + clearContext(): void { + this.context = {}; + this.pinoLogger = basePinoLogger; + } + + child(context: LogContext): Logger { + return new Logger({ ...this.context, ...context }); + } + + info(message: string, additionalContext?: LogContext): void { + this.pinoLogger.info(additionalContext ?? {}, message); + writeToDebugBucket("INFO", message, () => ({ + ...this.context, + ...additionalContext, + })); + } + + warn(message: string, additionalContext?: LogContext): void { + this.pinoLogger.warn(additionalContext ?? {}, message); + writeToDebugBucket("WARN", message, () => ({ + ...this.context, + ...additionalContext, + })); + } + + error(message: string, additionalContext?: LogContext): void { + this.pinoLogger.error(additionalContext ?? {}, message); + writeToDebugBucket("ERROR", message, () => ({ + ...this.context, + ...additionalContext, + })); + } + + debug(message: string, additionalContext?: LogContext): void { + this.pinoLogger.debug(additionalContext ?? {}, message); + writeToDebugBucket("DEBUG", message, () => ({ + ...this.context, + ...additionalContext, + })); + } +} + +export const logger = new Logger(); + +export function extractCorrelationId(event: unknown): string | undefined { + if (!event || typeof event !== "object" || !("id" in event)) return undefined; + const { id } = event as Record; + return typeof id === "string" ? id : undefined; +} + +export function logLifecycleEvent( + eventLogger: Logger, + stage: + | "processing-started" + | "transformation-started" + | "transformation-completed" + | "filtering-started" + | "filtering-matched" + | "delivery-initiated" + | "batch-processing-completed", + context: LogContext, +): void { + eventLogger.info(`Callback lifecycle: ${stage}`, context); +} diff --git a/src/logger/tsconfig.json b/src/logger/tsconfig.json new file mode 100644 index 0000000..64297cf --- /dev/null +++ b/src/logger/tsconfig.json @@ -0,0 +1,11 @@ +{ + "compilerOptions": { + "baseUrl": "src", + "isolatedModules": true + }, + "extends": "../../tsconfig.base.json", + "include": [ + "src/**/*", + "jest.config.ts" + ] +} diff --git a/tests/integration/dlq-redrive.test.ts b/tests/integration/dlq-redrive.test.ts new file mode 100644 index 0000000..afb995e --- /dev/null +++ b/tests/integration/dlq-redrive.test.ts @@ -0,0 +1,325 @@ +import { + DeleteMessageCommand, + GetQueueAttributesCommand, + SQSClient, + SendMessageCommand, +} from "@aws-sdk/client-sqs"; +import type { + MessageStatusData, + StatusPublishEvent, +} from "@nhs-notify-client-callbacks/models"; +import { EventTypes } from "@nhs-notify-client-callbacks/models"; +import { + awaitCallbacks, + awaitQueueEmpty, + awaitQueueMessage, + buildDebugLogBucketName, + buildInboundEventQueueUrl, + createS3Client, + createSqsClient, + deleteDebugLogEntries, + getDeploymentDetails, + getMessageStatusCallbacksFromBucket, + listClientDlqUrls, +} from "helpers"; +import { S3Client } from "@aws-sdk/client-s3"; + +describe("DLQ Redrive", () => { + let sqsClient: SQSClient; + let s3Client: S3Client; + let dlqQueueUrls: string[]; + let dlqQueueUrl!: string; + let inboundQueueUrl: string; + let debugLogBucketName: string; + let workflowTestsPassed = 0; + + beforeAll(async () => { + const deploymentDetails = getDeploymentDetails(); + sqsClient = createSqsClient(); + s3Client = createS3Client(); + + inboundQueueUrl = buildInboundEventQueueUrl(deploymentDetails); + debugLogBucketName = buildDebugLogBucketName(deploymentDetails); + dlqQueueUrls = await listClientDlqUrls(sqsClient, deploymentDetails); + [dlqQueueUrl] = dlqQueueUrls; + + if (dlqQueueUrls.length === 0) { + throw new Error( + "No per-client DLQs found. " + + "Ensure the environment is deployed with deploy_mock_webhook=true.", + ); + } + }); + + afterAll(async () => { + if (workflowTestsPassed === 2) { + await deleteDebugLogEntries(s3Client, debugLogBucketName); + } + sqsClient?.destroy(); + s3Client?.destroy(); + }); + + describe("Infrastructure validation", () => { + it("should discover at least one per-client DLQ", () => { + expect(dlqQueueUrls.length).toBeGreaterThan(0); + }); + + it("should confirm the first discovered per-client DLQ is accessible", async () => { + const response = await sqsClient.send( + new GetQueueAttributesCommand({ + QueueUrl: dlqQueueUrl, + AttributeNames: ["QueueArn", "ApproximateNumberOfMessages"], + }), + ); + + expect(response.Attributes?.QueueArn).toBeDefined(); + }); + + it("should confirm the inbound event queue exists and is accessible", async () => { + const response = await sqsClient.send( + new GetQueueAttributesCommand({ + QueueUrl: inboundQueueUrl, + AttributeNames: ["QueueArn", "ApproximateNumberOfMessages"], + }), + ); + + expect(response.Attributes?.QueueArn).toBeDefined(); + }); + }); + + describe("Redrive workflow", () => { + it("should successfully reprocess an event moved from the DLQ back to the inbound queue", async () => { + if (!process.env.TEST_MOCK_WEBHOOK_URL) { + return; + } + + const messageId = `dlq-redrive-test-${Date.now()}`; + const event: StatusPublishEvent = { + specversion: "1.0", + id: crypto.randomUUID(), + source: "/nhs/england/notify/development/primary/data-plane/messaging", + subject: `customer/${crypto.randomUUID()}/message/${messageId}`, + type: EventTypes.MESSAGE_STATUS_PUBLISHED, + time: new Date().toISOString(), + datacontenttype: "application/json", + dataschema: + "https://notify.nhs.uk/schemas/message-status-published-v1.json", + traceparent: "00-4d678967f96e353c07a0a31c1849b500-07f83ba58dd8df70-01", + data: { + clientId: "mock-client", + messageId, + messageReference: `dlq-redrive-ref-${Date.now()}`, + messageStatus: "DELIVERED", + messageStatusDescription: "DLQ redrive integration test — delivered", + channels: [ + { + type: "NHSAPP", + channelStatus: "DELIVERED", + }, + ], + timestamp: new Date().toISOString(), + routingPlan: { + id: crypto.randomUUID(), + name: "DLQ redrive test routing plan", + version: "v1.0.0", + createdDate: new Date().toISOString(), + }, + }, + }; + + await sqsClient.send( + new SendMessageCommand({ + QueueUrl: dlqQueueUrl, + MessageBody: JSON.stringify(event), + }), + ); + + const deadMessage = await awaitQueueMessage(sqsClient, dlqQueueUrl); + + expect(deadMessage.Body).toBeDefined(); + const redrivePayload = JSON.parse(deadMessage.Body as string); + expect(redrivePayload.data.messageId).toBe(messageId); + + const redriveTime = new Date(); + + await sqsClient.send( + new SendMessageCommand({ + QueueUrl: inboundQueueUrl, + MessageBody: deadMessage.Body!, + }), + ); + + await sqsClient.send( + new DeleteMessageCommand({ + QueueUrl: dlqQueueUrl, + ReceiptHandle: deadMessage.ReceiptHandle!, + }), + ); + + // Poll S3 in parallel with awaitQueueEmpty — the delivery pipeline + // (client-transform-filter → EventBridge → mock-webhook) is async, so + // S3 entries can arrive after the inbound queue appears empty. + const [, callbacks] = await Promise.all([ + awaitQueueEmpty( + sqsClient, + inboundQueueUrl, + [ + "ApproximateNumberOfMessages", + "ApproximateNumberOfMessagesNotVisible", + ], + 90_000, + ), + awaitCallbacks( + () => + getMessageStatusCallbacksFromBucket( + s3Client, + debugLogBucketName, + messageId, + redriveTime, + ), + 120_000, + `MessageStatus:${messageId}`, + ), + ]); + + expect(callbacks.length).toBeGreaterThan(0); + expect(callbacks[0]).toMatchObject({ + type: "MessageStatus", + attributes: expect.objectContaining({ + messageStatus: "delivered", + }), + }); + workflowTestsPassed += 1; + }, 180_000); + + it("should apply the same transformation logic to redriven events as original deliveries", async () => { + if (!process.env.TEST_MOCK_WEBHOOK_URL) { + return; + } + + const directMessageId = `direct-${Date.now()}`; + const redriveMessageId = `redriven-${Date.now()}`; + + const directStartTime = new Date(); + + const buildEvent = ( + messageId: string, + ): StatusPublishEvent => ({ + specversion: "1.0", + id: crypto.randomUUID(), + source: "/nhs/england/notify/development/primary/data-plane/messaging", + subject: `customer/${crypto.randomUUID()}/message/${messageId}`, + type: EventTypes.MESSAGE_STATUS_PUBLISHED, + time: new Date().toISOString(), + datacontenttype: "application/json", + dataschema: + "https://notify.nhs.uk/schemas/message-status-published-v1.json", + traceparent: "00-4d678967f96e353c07a0a31c1849b500-07f83ba58dd8df70-03", + data: { + clientId: "mock-client", + messageId, + messageReference: `ref-${messageId}`, + messageStatus: "DELIVERED", + messageStatusDescription: "Transformation consistency test", + channels: [ + { + type: "NHSAPP", + channelStatus: "DELIVERED", + }, + ], + timestamp: new Date().toISOString(), + routingPlan: { + id: crypto.randomUUID(), + name: "Consistency test routing plan", + version: "v1.0.0", + createdDate: new Date().toISOString(), + }, + }, + }); + + await sqsClient.send( + new SendMessageCommand({ + QueueUrl: inboundQueueUrl, + MessageBody: JSON.stringify(buildEvent(directMessageId)), + }), + ); + + await sqsClient.send( + new SendMessageCommand({ + QueueUrl: dlqQueueUrl, + MessageBody: JSON.stringify(buildEvent(redriveMessageId)), + }), + ); + + const dlqMessage = await awaitQueueMessage(sqsClient, dlqQueueUrl); + + expect(dlqMessage.Body).toBeDefined(); + const dlqPayload = JSON.parse(dlqMessage.Body as string); + expect(dlqPayload.data.messageId).toBe(redriveMessageId); + + const redriveTime = new Date(); + + await sqsClient.send( + new SendMessageCommand({ + QueueUrl: inboundQueueUrl, + MessageBody: dlqMessage.Body!, + }), + ); + + await sqsClient.send( + new DeleteMessageCommand({ + QueueUrl: dlqQueueUrl, + ReceiptHandle: dlqMessage.ReceiptHandle!, + }), + ); + + // Poll S3 in parallel with awaitQueueEmpty — the delivery pipeline is + // async so entries can arrive after the inbound queue appears empty. + const [[directCallbacks, redriveCallbacks]] = await Promise.all([ + Promise.all([ + awaitCallbacks( + () => + getMessageStatusCallbacksFromBucket( + s3Client, + debugLogBucketName, + directMessageId, + directStartTime, + ), + 120_000, + `MessageStatus:${directMessageId}`, + ), + awaitCallbacks( + () => + getMessageStatusCallbacksFromBucket( + s3Client, + debugLogBucketName, + redriveMessageId, + redriveTime, + ), + 120_000, + `MessageStatus:${redriveMessageId}`, + ), + ]), + awaitQueueEmpty( + sqsClient, + inboundQueueUrl, + [ + "ApproximateNumberOfMessages", + "ApproximateNumberOfMessagesNotVisible", + ], + 90_000, + ), + ]); + + expect(redriveCallbacks[0]).toMatchObject({ + type: directCallbacks[0].type, + attributes: expect.objectContaining({ + messageStatus: ( + directCallbacks[0].attributes as { messageStatus?: string } + ).messageStatus, + }), + }); + workflowTestsPassed += 1; + }, 180_000); + }); +}); diff --git a/tests/integration/event-bus-to-webhook.test.ts b/tests/integration/event-bus-to-webhook.test.ts index d13bb18..9f37b96 100644 --- a/tests/integration/event-bus-to-webhook.test.ts +++ b/tests/integration/event-bus-to-webhook.test.ts @@ -1,132 +1,15 @@ -import { - GetQueueAttributesCommand, - PurgeQueueCommand, - SQSClient, - SendMessageCommand, -} from "@aws-sdk/client-sqs"; -import { waitUntil } from "async-wait-until"; +import { PurgeQueueCommand, SQSClient } from "@aws-sdk/client-sqs"; import type { MessageStatusData, StatusPublishEvent, } from "@nhs-notify-client-callbacks/models"; -import { getChannelStatusCallbacks, getMessageStatusCallbacks } from "helpers"; - -const publishEvent = async ( - client: SQSClient, - queueUrl: string, - event: StatusPublishEvent, -) => { - const sendMessageCommand = new SendMessageCommand({ - QueueUrl: queueUrl, - MessageBody: JSON.stringify(event), - }); - - return client.send(sendMessageCommand); -}; - -const getQueueMessageCount = async ( - client: SQSClient, - queueUrl?: string, - attributeNames: ( - | "ApproximateNumberOfMessages" - | "ApproximateNumberOfMessagesNotVisible" - )[] = ["ApproximateNumberOfMessages"], -) => { - if (!queueUrl) { - return 0; - } - - const queueAttributesCommand = new GetQueueAttributesCommand({ - QueueUrl: queueUrl, - AttributeNames: attributeNames, - }); - - const queueAttributes = await client.send(queueAttributesCommand); - const { ApproximateNumberOfMessages, ApproximateNumberOfMessagesNotVisible } = - queueAttributes.Attributes ?? {}; - - let count = 0; - - if (attributeNames.includes("ApproximateNumberOfMessages")) { - count += Number(ApproximateNumberOfMessages || 0); - } - - if (attributeNames.includes("ApproximateNumberOfMessagesNotVisible")) { - count += Number(ApproximateNumberOfMessagesNotVisible || 0); - } - - return count; -}; - -const awaitQueueEmpty = async ( - client: SQSClient, - queueUrl?: string, - attributeNames: ( - | "ApproximateNumberOfMessages" - | "ApproximateNumberOfMessagesNotVisible" - )[] = ["ApproximateNumberOfMessages"], -) => { - if (!queueUrl) { - return; - } - - await waitUntil( - async () => - (await getQueueMessageCount(client, queueUrl, attributeNames)) === 0, - { - intervalBetweenAttempts: 250, - timeout: 10_000, - }, - ); -}; - -const awaitMessageStatusCallbacks = async ( - logGroup: string, - messageId: string, -) => { - let callbacks: Awaited> = []; - - await waitUntil( - async () => { - callbacks = await getMessageStatusCallbacks(logGroup, messageId); - return callbacks.length > 0; - }, - { - intervalBetweenAttempts: 500, - timeout: 10_000, - }, - ); - - if (callbacks.length === 0) { - throw new Error("Timed out waiting for message status callbacks"); - } - - return callbacks; -}; - -const awaitChannelStatusCallbacks = async ( - logGroup: string, - messageId: string, -) => { - let callbacks: Awaited> = []; - - await waitUntil( - async () => { - callbacks = await getChannelStatusCallbacks(logGroup, messageId); - return callbacks.length > 0; - }, - { - intervalBetweenAttempts: 500, - timeout: 10_000, - }, - ); - - if (callbacks.length === 0) { - throw new Error("Timed out waiting for channel status callbacks"); - } - - return callbacks; -}; +import { + awaitCallbacks, + awaitChannelStatusCallbacks, + awaitQueueEmpty, + getMessageStatusCallbacks, + sendSqsEvent, +} from "helpers"; // eslint-disable-next-line jest/no-disabled-tests describe.skip("SQS to Webhook Integration", () => { @@ -212,7 +95,7 @@ describe.skip("SQS to Webhook Integration", () => { }, }; - const sendMessageResponse = await publishEvent( + const sendMessageResponse = await sendSqsEvent( sqsClient, TEST_CALLBACK_EVENT_QUEUE_URL, messageStatusEvent, @@ -225,9 +108,13 @@ describe.skip("SQS to Webhook Integration", () => { "ApproximateNumberOfMessagesNotVisible", ]); - const callbacks = await awaitMessageStatusCallbacks( - TEST_MOCK_WEBHOOK_LOG_GROUP, - messageStatusEvent.data.messageId, + const callbacks = await awaitCallbacks( + () => + getMessageStatusCallbacks( + TEST_MOCK_WEBHOOK_LOG_GROUP, + messageStatusEvent.data.messageId, + ), + 10_000, ); expect(callbacks).toHaveLength(1); @@ -286,7 +173,7 @@ describe.skip("SQS to Webhook Integration", () => { }, }; - const sendMessageResponse = await publishEvent( + const sendMessageResponse = await sendSqsEvent( sqsClient, TEST_CALLBACK_EVENT_QUEUE_URL, channelStatusEvent, diff --git a/tests/integration/helpers/aws-helpers.ts b/tests/integration/helpers/aws-helpers.ts index c4c2ebe..33941cb 100644 --- a/tests/integration/helpers/aws-helpers.ts +++ b/tests/integration/helpers/aws-helpers.ts @@ -1,39 +1,66 @@ -import { S3Client } from "@aws-sdk/client-s3"; +import { + DeleteObjectsCommand, + GetObjectCommand, + ListObjectsV2Command, + S3Client, +} from "@aws-sdk/client-s3"; +import { + GetQueueAttributesCommand, + ListQueuesCommand, + ReceiveMessageCommand, + SQSClient, + SendMessageCommand, +} from "@aws-sdk/client-sqs"; +import type { CallbackItem } from "@nhs-notify-client-callbacks/models"; +import { waitUntil } from "async-wait-until"; export type DeploymentDetails = { region: string; environment: string; + project: string; + component: string; accountId: string; }; /** * Reads deployment context from environment variables * - * Requires: AWS_REGION, ENVIRONMENT, AWS_ACCOUNT_ID + * Requires: AWS_REGION, ENVIRONMENT, PROJECT, COMPONENT, AWS_ACCOUNT_ID */ export function getDeploymentDetails(): DeploymentDetails { const region = process.env.AWS_REGION ?? "eu-west-2"; const environment = process.env.ENVIRONMENT; + const project = process.env.PROJECT; + const component = process.env.COMPONENT; const accountId = process.env.AWS_ACCOUNT_ID; if (!environment) { throw new Error("ENVIRONMENT environment variable must be set"); } + if (!project) { + throw new Error("PROJECT environment variable must be set"); + } + if (!component) { + throw new Error("COMPONENT environment variable must be set"); + } if (!accountId) { throw new Error("AWS_ACCOUNT_ID environment variable must be set"); } - return { region, environment, accountId }; + return { region, environment, project, component, accountId }; } /** - * Builds an S3 bucket name from deployment details and a bucket-specific suffix. + * Builds the subscription config S3 bucket name from deployment details. */ -export function buildBucketName( - { accountId, environment, region }: DeploymentDetails, - suffix: string, -): string { - return `nhs-${accountId}-${region}-${environment}-${suffix}`; +export function buildSubscriptionConfigBucketName({ + accountId, + component, + environment, + project, + region, +}: DeploymentDetails): string { + return `${project}-${accountId}-${region}-${environment}-${component}-subscription-config`; } /** @@ -43,3 +70,402 @@ export function createS3Client(): S3Client { const region = process.env.AWS_REGION ?? "eu-west-2"; return new S3Client({ region }); } + +/** + * Creates an SQS client configured for the given region. + */ +export function createSqsClient(): SQSClient { + const region = process.env.AWS_REGION ?? "eu-west-2"; + return new SQSClient({ region }); +} + +/** + * Builds the SQS queue URL from deployment details and queue name suffix. + */ +export function buildQueueUrl( + { accountId, component, environment, project, region }: DeploymentDetails, + name: string, +): string { + const queueName = `${project}-${environment}-${component}-${name}-queue`; + return `https://sqs.${region}.amazonaws.com/${accountId}/${queueName}`; +} + +/** + * Builds the inbound event SQS queue URL from deployment details. + */ +export function buildInboundEventQueueUrl( + deploymentDetails: DeploymentDetails, +): string { + return buildQueueUrl(deploymentDetails, "inbound-event"); +} + +/** + * Discovers all per-client DLQ URLs for the given deployment. + */ +export async function listClientDlqUrls( + client: SQSClient, + { component, environment, project }: DeploymentDetails, +): Promise { + const csi = `${project}-${environment}-${component}`; + + const response = await client.send( + new ListQueuesCommand({ + QueueNamePrefix: csi, + MaxResults: 100, + }), + ); + + return (response.QueueUrls ?? []).filter( + (url) => url.endsWith("-dlq-queue") && !url.includes("inbound-event"), + ); +} + +/** + * Builds the CloudWatch log group name for the mock webhook Lambda. + */ +export function buildMockWebhookLogGroupName({ + component, + environment, + project, +}: DeploymentDetails): string { + return `/aws/lambda/${project}-${environment}-${component}-mock-webhook`; +} + +/** + * Sends a JSON-serialised event to an SQS queue. + */ +export async function sendSqsEvent( + client: SQSClient, + queueUrl: string, + event: T, +) { + return client.send( + new SendMessageCommand({ + QueueUrl: queueUrl, + MessageBody: JSON.stringify(event), + }), + ); +} + +/** + * Returns the approximate number of messages in the given SQS queue. + * Returns 0 if queueUrl is undefined. + */ +export async function getQueueMessageCount( + client: SQSClient, + queueUrl?: string, + attributeNames: ( + | "ApproximateNumberOfMessages" + | "ApproximateNumberOfMessagesNotVisible" + )[] = ["ApproximateNumberOfMessages"], +): Promise { + if (!queueUrl) { + return 0; + } + + const response = await client.send( + new GetQueueAttributesCommand({ + QueueUrl: queueUrl, + AttributeNames: attributeNames, + }), + ); + + const attrs = response.Attributes ?? {}; + return attributeNames.reduce( + // eslint-disable-next-line security/detect-object-injection -- attr is a known enum value from the caller + (sum, attr) => sum + Number(attrs[attr] ?? 0), + 0, + ); +} + +/** + * Waits until the given SQS queue is empty, polling until all visible messages + * are processed or the timeout is exceeded. + */ +export async function awaitQueueEmpty( + client: SQSClient, + queueUrl?: string, + attributeNames: ( + | "ApproximateNumberOfMessages" + | "ApproximateNumberOfMessagesNotVisible" + )[] = ["ApproximateNumberOfMessages"], + timeoutMs = 10_000, +): Promise { + if (!queueUrl) { + return; + } + + const queueLabel = queueUrl.split("/").pop() ?? queueUrl; + const deadline = Date.now() + timeoutMs; + + while (Date.now() < deadline) { + const count = await getQueueMessageCount(client, queueUrl, attributeNames); + + if (count === 0) { + return; + } + + await new Promise((resolve) => { + setTimeout(resolve, 250); + }); + } + + throw new Error( + `Timed out after ${timeoutMs}ms waiting for queue to empty: ${queueLabel}`, + ); +} + +/** + * Receives a single message from the given SQS queue. + * Returns undefined if no message is available within the visibility window. + */ +export async function receiveOneMessage(client: SQSClient, queueUrl: string) { + const response = await client.send( + new ReceiveMessageCommand({ + QueueUrl: queueUrl, + MaxNumberOfMessages: 1, + WaitTimeSeconds: 5, + VisibilityTimeout: 30, + }), + ); + return response.Messages?.[0]; +} + +/** + * Waits for a message to appear in the given SQS queue, polling until a message + * is received or the timeout is exceeded. + */ +export async function awaitQueueMessage( + client: SQSClient, + queueUrl: string, + timeoutMs = 30_000, +) { + let message: Awaited>; + + await waitUntil( + async () => { + message = await receiveOneMessage(client, queueUrl); + return message !== undefined; + }, + { + intervalBetweenAttempts: 500, + timeout: timeoutMs, + }, + ); + + if (!message) { + throw new Error( + `Timed out after ${timeoutMs}ms waiting for a message to appear in ${queueUrl}`, + ); + } + + return message; +} + +/** + * Builds the S3 debug log bucket name from deployment details. + */ +export function buildDebugLogBucketName({ + accountId, + component, + environment, + project, + region, +}: DeploymentDetails): string { + return `${project}-${accountId}-${region}-${environment}-${component}-debug-log`; +} + +type DebugLogEntry = { + level: string; + message: string; + timestamp: string; + [key: string]: unknown; +}; + +async function listDebugLogEntries( + client: S3Client, + bucketName: string, +): Promise { + const listResponse = await client.send( + new ListObjectsV2Command({ Bucket: bucketName }), + ); + + const keys = (listResponse.Contents ?? []) + .map((obj) => obj.Key) + .filter((key): key is string => key !== undefined); + + const entries = await Promise.all( + keys.map(async (key) => { + const obj = await client.send( + new GetObjectCommand({ Bucket: bucketName, Key: key }), + ); + const body = await obj.Body?.transformToString(); + if (!body) return null; + try { + return JSON.parse(body) as DebugLogEntry; + } catch { + return null; + } + }), + ); + + return entries.filter((entry): entry is DebugLogEntry => entry !== null); +} + +function parseCallbackFromMessage(message: string): CallbackItem | null { + const match = /CALLBACK .+ : (.+)$/.exec(message); + if (!match?.[1]) return null; + try { + return JSON.parse(match[1]) as CallbackItem; + } catch { + return null; + } +} + +/** + * Constructs a CallbackItem from a "Callback generated" structured log entry. + * These entries come from client-transform-filter-lambda and store callback + * fields as structured JSON properties rather than embedded in the message. + */ +function buildCallbackItemFromGeneratedEntry( + entry: DebugLogEntry, +): CallbackItem { + return { + type: entry.callbackType as "MessageStatus" | "ChannelStatus", + attributes: { + messageId: entry.messageId as string, + messageReference: entry.messageReference as string, + ...(entry.callbackType === "MessageStatus" + ? { + messageStatus: entry.messageStatus, + messageStatusDescription: entry.messageStatusDescription, + channels: entry.channels, + timestamp: entry.timestamp, + routingPlan: entry.routingPlan ?? {}, + } + : { + channel: entry.channel, + channelStatus: entry.channelStatus, + channelStatusDescription: entry.channelStatusDescription, + supplierStatus: entry.supplierStatus, + cascadeType: entry.cascadeType, + cascadeOrder: entry.cascadeOrder, + timestamp: entry.timestamp, + retryCount: entry.retryCount ?? 0, + }), + } as unknown as CallbackItem["attributes"], + links: { message: entry.messageId as string }, + meta: { idempotencyKey: (entry.correlationId as string) ?? "" }, + }; +} + +async function getCallbacksFromBucket( + client: S3Client, + bucketName: string, + callbackType: "MessageStatus" | "ChannelStatus", + messageId: string, + startTime?: Date, +): Promise { + const entries = await listDebugLogEntries(client, bucketName); + + return entries + .filter((entry) => { + if (startTime && new Date(entry.timestamp) < startTime) { + return false; + } + // CALLBACK entries from mock-webhook-lambda: messageId is embedded in the + // serialised JSON within the message string. + if ( + entry.message.startsWith("CALLBACK") && + entry.message.includes(callbackType) + ) { + return entry.message.includes(messageId); + } + // "Callback generated" entries from client-transform-filter-lambda: + // messageId is a top-level structured field, not part of the message. + if (entry.message === "Callback generated") { + return ( + entry.callbackType === callbackType && + (entry.messageId as string) === messageId + ); + } + return false; + }) + .map((entry): CallbackItem | null => { + if (entry.message.startsWith("CALLBACK")) { + return parseCallbackFromMessage(entry.message); + } + return buildCallbackItemFromGeneratedEntry(entry); + }) + .filter((item): item is CallbackItem => item !== null); +} + +/** + * Reads MessageStatus callback entries from the S3 debug log bucket. + * + * Handles two entry types: + * - "CALLBACK ... MessageStatus : " entries from mock-webhook-lambda + * (full CallbackItem payload already serialised in the message) + * - "Callback generated" entries from client-transform-filter-lambda + * (messageId and callbackType stored as structured fields, not in message) + */ +export async function getMessageStatusCallbacksFromBucket( + client: S3Client, + bucketName: string, + messageId: string, + startTime?: Date, +): Promise { + return getCallbacksFromBucket( + client, + bucketName, + "MessageStatus", + messageId, + startTime, + ); +} + +/** + * Reads ChannelStatus callback entries from the S3 debug log bucket. + * + * Handles the same two entry types as getMessageStatusCallbacksFromBucket, + * filtered for ChannelStatus callbacks. + */ +export async function getChannelStatusCallbacksFromBucket( + client: S3Client, + bucketName: string, + messageId: string, + startTime?: Date, +): Promise { + return getCallbacksFromBucket( + client, + bucketName, + "ChannelStatus", + messageId, + startTime, + ); +} + +/** + * Deletes all debug log entries for the given test run from the S3 bucket. + */ +export async function deleteDebugLogEntries( + client: S3Client, + bucketName: string, +): Promise { + const listResponse = await client.send( + new ListObjectsV2Command({ Bucket: bucketName }), + ); + + const objects = listResponse.Contents ?? []; + if (objects.length === 0) return; + + await client.send( + new DeleteObjectsCommand({ + Bucket: bucketName, + Delete: { + Objects: objects.map((obj) => ({ Key: obj.Key! })), + Quiet: true, + }, + }), + ); +} diff --git a/tests/integration/helpers/cloudwatch-helpers.ts b/tests/integration/helpers/cloudwatch-helpers.ts index 698450a..2c86199 100644 --- a/tests/integration/helpers/cloudwatch-helpers.ts +++ b/tests/integration/helpers/cloudwatch-helpers.ts @@ -1,32 +1,72 @@ import { CloudWatchLogsClient, - FilterLogEventsCommand, + GetQueryResultsCommand, + StartQueryCommand, } from "@aws-sdk/client-cloudwatch-logs"; +import { waitUntil } from "async-wait-until"; import type { CallbackItem } from "@nhs-notify-client-callbacks/models"; const client = new CloudWatchLogsClient({ - region: process.env.REGION ?? "eu-west-2", + region: process.env.AWS_REGION ?? "eu-west-2", }); export async function getCallbackLogsFromCloudWatch( logGroupName: string, - pattern: string, + terms: string[], startTime?: Date, ): Promise { - const searchStartTime = startTime || new Date(Date.now() - 5 * 60 * 1000); + const searchStartTime = startTime ?? new Date(Date.now() - 5 * 60 * 1000); - const filterEvents = new FilterLogEventsCommand({ - logGroupName, - startTime: searchStartTime.getTime(), - filterPattern: pattern, - limit: 100, - }); + const filterClauses = terms + .map((term) => `| filter @message like "${term}"`) + .join(" "); + const queryString = `fields @message ${filterClauses} | sort @timestamp desc | limit 100`; - const { events = [] } = await client.send(filterEvents); + const startEpoch = Math.floor(searchStartTime.getTime() / 1000); + const endEpoch = Math.floor(Date.now() / 1000) + 30; - return events.flatMap(({ message }) => - message ? [JSON.parse(message)] : [], + const { queryId } = await client.send( + new StartQueryCommand({ + logGroupName, + startTime: startEpoch, + endTime: endEpoch, + queryString, + }), ); + + if (!queryId) { + return []; + } + + for (let i = 0; i < 20; i++) { + await new Promise((resolve) => { + setTimeout(resolve, 500); + }); + + const { results = [], status } = await client.send( + new GetQueryResultsCommand({ queryId }), + ); + + if (status === "Complete") { + const parsed = results + .map((fields) => { + const messageField = fields.find((f) => f.field === "@message"); + return messageField?.value + ? (JSON.parse(messageField.value) as unknown) + : null; + }) + .filter((v): v is unknown => v !== null); + return parsed; + } + + if (status === "Failed" || status === "Cancelled" || status === "Timeout") { + throw new Error( + `CloudWatch Insights query ${status}: queryId=${queryId}`, + ); + } + } + + return []; } export function parseCallbacksFromLogs(logs: unknown[]): CallbackItem[] { @@ -59,7 +99,7 @@ export async function getMessageStatusCallbacks( ): Promise { const logs = await getCallbackLogsFromCloudWatch( logGroupName, - `%${requestItemId}%MessageStatus%`, + [requestItemId, "MessageStatus"], startTime, ); return parseCallbacksFromLogs(logs); @@ -72,7 +112,7 @@ export async function getChannelStatusCallbacks( ): Promise { const logs = await getCallbackLogsFromCloudWatch( logGroupName, - `%${requestItemId}%ChannelStatus%`, + [requestItemId, "ChannelStatus"], startTime, ); return parseCallbacksFromLogs(logs); @@ -85,8 +125,70 @@ export async function getAllCallbacks( ): Promise { const logs = await getCallbackLogsFromCloudWatch( logGroupName, - `"${requestItemId}"`, + [requestItemId], startTime, ); return parseCallbacksFromLogs(logs); } + +export const awaitChannelStatusCallbacks = async ( + logGroup: string, + messageId: string, +) => { + let callbacks: Awaited> = []; + + await waitUntil( + async () => { + callbacks = await getChannelStatusCallbacks(logGroup, messageId); + return callbacks.length > 0; + }, + { + intervalBetweenAttempts: 500, + timeout: 10_000, + }, + ); + + if (callbacks.length === 0) { + throw new Error("Timed out waiting for channel status callbacks"); + } + + return callbacks; +}; + +/** + * Polls a callback getter function until it returns at least one result or the + * timeout is exceeded. Throws if no results arrive within the timeout. + * + * @example + * const callbacks = await awaitCallbacks( + * () => getMessageStatusCallbacks(logGroupName, messageId), + * 10_000, + * ); + */ +export async function awaitCallbacks( + getter: () => Promise, + timeoutMs = 30_000, + label?: string, +): Promise { + let results: T[] = []; + + await waitUntil( + async () => { + results = await getter(); + return results.length > 0; + }, + { + intervalBetweenAttempts: 500, + timeout: timeoutMs, + }, + ); + + if (results.length === 0) { + const labelSuffix = label ? ` (${label})` : ""; + throw new Error( + `Timed out after ${timeoutMs}ms waiting for callbacks${labelSuffix}`, + ); + } + + return results; +} diff --git a/tests/integration/infrastructure-exists.test.ts b/tests/integration/infrastructure-exists.test.ts index bf53f2c..62a8186 100644 --- a/tests/integration/infrastructure-exists.test.ts +++ b/tests/integration/infrastructure-exists.test.ts @@ -1,6 +1,10 @@ import { HeadBucketCommand } from "@aws-sdk/client-s3"; import type { S3Client } from "@aws-sdk/client-s3"; -import { buildBucketName, createS3Client, getDeploymentDetails } from "helpers"; +import { + buildSubscriptionConfigBucketName, + createS3Client, + getDeploymentDetails, +} from "helpers"; describe("Infrastructure exists", () => { let s3Client: S3Client; @@ -8,10 +12,7 @@ describe("Infrastructure exists", () => { beforeAll(async () => { const deploymentDetails = getDeploymentDetails(); - bucketName = buildBucketName( - deploymentDetails, - "callbacks-subscription-config", - ); + bucketName = buildSubscriptionConfigBucketName(deploymentDetails); s3Client = createS3Client(); }); diff --git a/tests/integration/tsconfig.json b/tests/integration/tsconfig.json index a5cc2b8..00cb81a 100644 --- a/tests/integration/tsconfig.json +++ b/tests/integration/tsconfig.json @@ -5,6 +5,18 @@ "paths": { "helpers": [ "./helpers/index" + ], + "models/*": [ + "../../lambdas/client-transform-filter-lambda/src/models/*" + ], + "services/*": [ + "../../lambdas/client-transform-filter-lambda/src/services/*" + ], + "transformers/*": [ + "../../lambdas/client-transform-filter-lambda/src/transformers/*" + ], + "validators/*": [ + "../../lambdas/client-transform-filter-lambda/src/validators/*" ] } },