Skip to content

CCM-15342: Logging in lambdas #366

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
nhsd-angel-pastor wants to merge 2 commits into
base: main
Choose a base branch
from
Draft

CCM-15342: Logging in lambdas #366

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
91a50cf
CCM-15342: Set python lambdas the log level
nhsd-angel-pastor May 20, 2026
ec1517e
CCM-15342: logging
nhsd-angel-pastor May 20, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 16 additions & 4 deletions lambdas/file-scanner-lambda/src/__tests__/apis/sqs-handler.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import { EventPublisher, Logger } from 'utils';
const mockFileScanner = mockDeep<FileScanner>();
const mockEventPublisher = mockDeep<EventPublisher>();
const mockLogger = mockDeep<Logger>();
const mockChildLogger = mockDeep<Logger>();

const createSQSEvent = (
records: {
Expand Down Expand Up @@ -68,6 +69,7 @@ describe('SQS Handler', () => {

beforeEach(() => {
jest.clearAllMocks();
mockLogger.child.mockReturnValue(mockChildLogger);
dependencies = {
eventPublisher: mockEventPublisher,
logger: mockLogger,
Expand Down Expand Up @@ -107,9 +109,15 @@ describe('SQS Handler', () => {
}),
);

expect(mockLogger.info).toHaveBeenCalledWith(
expect(mockChildLogger.info).toHaveBeenCalledWith(
expect.objectContaining({
description: 'Processing ItemDequeued event',
}),
);

expect(mockLogger.child).toHaveBeenCalledWith(
expect.objectContaining({
messageId: 'msg-001',
messageReference: 'ref-001',
senderId: 'SENDER_001',
}),
Expand Down Expand Up @@ -192,9 +200,14 @@ describe('SQS Handler', () => {
{ itemIdentifier: 'msg-001' },
]);

expect(mockLogger.error).toHaveBeenCalledWith(
expect(mockChildLogger.error).toHaveBeenCalledWith(
expect.objectContaining({
description: 'Error processing record',
}),
);

expect(mockLogger.child).toHaveBeenCalledWith(
expect.objectContaining({
messageId: 'msg-001',
}),
);
Expand Down Expand Up @@ -300,11 +313,10 @@ describe('SQS Handler', () => {
{ itemIdentifier: 'msg-002' },
]);

expect(mockLogger.error).toHaveBeenCalledWith(
expect(mockChildLogger.error).toHaveBeenCalledWith(
expect.objectContaining({
description: 'Error processing record',
err: 'string error',
messageId: 'msg-002',
}),
);
});
Expand Down
20 changes: 14 additions & 6 deletions lambdas/file-scanner-lambda/src/apis/sqs-handler.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ function validateRecord(
logger.warn({
err: error,
description: 'Error parsing SQS record',
messageId,
});
return null;
}
Expand All @@ -42,13 +43,16 @@ async function processRecord(
validatedRecord: ValidatedRecord,
{ fileScanner, logger }: HandlerDependencies,
): Promise<void> {
const { event } = validatedRecord;
const { event, messageId } = validatedRecord;
const recordLogger = logger.child({
messageId,
messageReference: event.data.messageReference,
senderId: event.data.senderId,
});

logger.info({
recordLogger.info({
description: 'Processing ItemDequeued event',
eventId: event.id,
messageReference: event.data.messageReference,
senderId: event.data.senderId,
});

const result = await fileScanner.scanFile(event.data.messageUri, {
Expand Down Expand Up @@ -82,7 +86,12 @@ export function createHandler(dependencies: HandlerDependencies) {
try {
await processRecord(validatedRecord, dependencies);
} catch (error) {
logger.error({
const recordLogger = logger.child({
messageId: validatedRecord.messageId,
messageReference: validatedRecord.event.data.messageReference,
senderId: validatedRecord.event.data.senderId,
});
recordLogger.error({
description: 'Error processing record',
err:
error instanceof Error
Expand All @@ -92,7 +101,6 @@ export function createHandler(dependencies: HandlerDependencies) {
stack: error.stack,
}
: error,
messageId: validatedRecord.messageId,
});

itemFailures.push({ itemIdentifier: validatedRecord.messageId });
Expand Down
8 changes: 2 additions & 6 deletions lambdas/mesh-acknowledge/mesh_acknowledge/events.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,15 +21,13 @@ def parse_downloaded_event(sqs_record, logger) -> MESHInboxMessageDownloaded:
except Exception as e:
logger.error(
"MESHInboxMessageDownloaded validation failed",
validation_errors=str(e),
event_detail=event_detail
Copy link
Copy Markdown
Contributor Author

@nhsd-angel-pastor nhsd-angel-pastor May 20, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not an issue as the event doesn't contain any PII, is just the message URI (the object key is an UUID anyway)

validation_errors=str(e)
)
raise ValueError(
"Error processing MESHInboxMessageDownloaded event") from e
except json.JSONDecodeError as e:
logger.error(
"Error parsing SQS record body as JSON",
body=sqs_record.get('body', ''),
error=str(e)
)
raise ValueError("Error parsing SQS record") from e
Expand All @@ -47,15 +45,13 @@ def parse_invalid_event(sqs_record, logger) -> MESHInboxMessageInvalid:
except Exception as e:
logger.error(
"MESHInboxMessageInvalid validation failed",
validation_errors=str(e),
event_detail=event_detail
validation_errors=str(e)
)
raise ValueError(
"Error processing MESHInboxMessageInvalid event") from e
except json.JSONDecodeError as e:
logger.error(
"Error parsing SQS record body as JSON",
body=sqs_record.get('body', ''),
error=str(e)
)
raise ValueError("Error parsing SQS record") from e
Expand Down
11 changes: 6 additions & 5 deletions lambdas/mesh-download/mesh_download/processor.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,10 @@ def __init__(self, **kwargs):
self.__storage_bucket = self.__config.transactional_data_bucket

def process_sqs_message(self, sqs_record):
sqs_message_id = sqs_record.get('messageId')
try:
validated_event = self._parse_and_validate_event(sqs_record)
logger = self.__log.bind(mesh_message_id=validated_event.data.meshMessageId)
validated_event = self._parse_and_validate_event(sqs_record, sqs_message_id)
logger = self.__log.bind(sqs_message_id=sqs_message_id, mesh_message_id=validated_event.data.meshMessageId)

logger.info("Processing MESH download request")
return self._handle_download(validated_event, logger)
Expand All @@ -37,11 +38,11 @@ def process_sqs_message(self, sqs_record):
self.__log.error(
"Error processing SQS message",
error=str(exc),
sqs_record=sqs_record
sqs_message_id=sqs_message_id
Copy link
Copy Markdown
Contributor Author

@nhsd-angel-pastor nhsd-angel-pastor May 20, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

MeshDownload event it's ok

)
raise

def _parse_and_validate_event(self, sqs_record):
def _parse_and_validate_event(self, sqs_record, sqs_message_id=None):
message_body = json.loads(sqs_record['body'])
event_detail = message_body.get('detail', {})

Expand All @@ -53,7 +54,7 @@ def _parse_and_validate_event(self, sqs_record):
self.__log.error(
"CloudEvent validation failed",
validation_errors=str(e),
event_detail=event_detail
Copy link
Copy Markdown
Contributor Author

@nhsd-angel-pastor nhsd-angel-pastor May 20, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

MeshMessageReceived is fine

sqs_message_id=sqs_message_id
)
raise

Expand Down
4 changes: 4 additions & 0 deletions lambdas/move-scanned-files-lambda/src/apis/sqs-handler.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,10 @@ export const createHandler = ({
}
} else {
// there was something wrong with the event
logger.warn({
description: 'Failed to process event',
messageId: sqsRecord.messageId,
});
batchItemFailures.push({ itemIdentifier: sqsRecord.messageId });
}
} catch (error: any) {
Expand Down
2 changes: 2 additions & 0 deletions lambdas/nhsapp-status-handler/src/apis/sqs-trigger-lambda.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ export const createHandler = ({
err: parseError,
messageReference:
sqsEventDetail?.data?.messageReference || 'not present',
messageId,
description: 'Error parsing sqs record',
});

Expand All @@ -66,6 +67,7 @@ export const createHandler = ({
logger.warn({
err: error,
description: 'Error during SQS trigger handler',
messageId,
});

batchItemFailures.push({ itemIdentifier: messageId });
Expand Down
4 changes: 4 additions & 0 deletions lambdas/pdm-poll-lambda/src/__tests__/apis/sqs-handler.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -254,6 +254,9 @@ describe('SQS Handler', () => {
expect(logger.warn).toHaveBeenCalledWith({
err: 'PDM error',
description: 'Failed processing message',
messageId: '1',
messageReference: pdmResourceSubmittedEvent.data.messageReference,
senderId: pdmResourceSubmittedEvent.data.senderId,
});

expect(logger.info).toHaveBeenCalledWith(
Expand All @@ -276,6 +279,7 @@ describe('SQS Handler', () => {
`Unexpected token 'o', "not-json" is not valid JSON`,
),
description: 'Error parsing SQS record',
messageId: '1',
});

expect(logger.info).toHaveBeenCalledWith(
Expand Down
4 changes: 4 additions & 0 deletions lambdas/pdm-poll-lambda/src/apis/sqs-handler.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@ function validateRecord(
logger.warn({
err: error,
description: 'Error parsing SQS record',
messageId,
});
return null;
}
Expand Down Expand Up @@ -184,6 +185,9 @@ export const createHandler = ({
logger.warn({
err: error.message,
description: 'Failed processing message',
messageId: validatedRecord.messageId,
messageReference: validatedRecord.event.data.messageReference,
senderId: validatedRecord.event.data.senderId,
});
batchItemFailures.push({ itemIdentifier: validatedRecord.messageId });
}
Expand Down
4 changes: 4 additions & 0 deletions lambdas/pdm-uploader-lambda/src/apis/sqs-trigger-lambda.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@ function validateRecord(
logger.error({
err: error,
description: 'Error parsing SQS record',
messageId,
});
return null;
}
Expand All @@ -73,6 +74,9 @@ async function processRecord(
logger.error({
err: error,
description: 'Error during SQS trigger handler',
messageId,
messageReference: event.data.messageReference,
senderId: event.data.senderId,
});
batchItemFailures.push({ itemIdentifier: messageId });
return { result: { outcome: 'failed' } };
Expand Down
8 changes: 5 additions & 3 deletions lambdas/print-analyser/src/__tests__/apis/sqs-handler.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -103,6 +103,7 @@ describe('SQS Handler', () => {
`Unexpected token 'o', "not-json" is not valid JSON`,
),
description: 'Error parsing SQS record',
messageId: '1',
});

expect(logger.info).toHaveBeenCalledWith(
Expand All @@ -124,7 +125,9 @@ describe('SQS Handler', () => {
const result = await handler(event);

expect(logger.child).toHaveBeenCalledWith({
messageId: '1',
messageReference: fileSafeEvent.data.messageReference,
senderId: fileSafeEvent.data.senderId,
});
expect(mockChildLogger.error).toHaveBeenCalledWith({
err: expect.arrayContaining([
Expand Down Expand Up @@ -177,7 +180,7 @@ describe('SQS Handler', () => {

const result = await handler(event);

expect(logger.warn).toHaveBeenCalledWith({
expect(mockChildLogger.warn).toHaveBeenCalledWith({
err: expect.objectContaining({ message: 'S3 GetObject failed' }),
description: 'Failed processing message',
});
Expand Down Expand Up @@ -230,9 +233,8 @@ describe('SQS Handler', () => {
expect.any(Function),
);

expect(logger.warn).toHaveBeenCalledWith({
expect(mockChildLogger.warn).toHaveBeenCalledWith({
err: expect.any(Error),
messageReference: fileSafeEvent.data.messageReference,
reasonCode: 'DL_CLIV_002',
description: 'Failed to analyze PDF - invalid attachment format',
});
Expand Down
18 changes: 12 additions & 6 deletions lambdas/print-analyser/src/apis/sqs-handler.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,8 @@ function validateRecord(

const messageReference =
sqsEventDetail?.data?.messageReference || 'not present';
const childLogger = logger.child({ messageReference });
const senderId = sqsEventDetail?.data?.senderId || 'not present';
const childLogger = logger.child({ messageId, messageReference, senderId });

validateFileSafe(sqsEventDetail, childLogger);

Expand All @@ -49,6 +50,7 @@ function validateRecord(
logger.warn({
err: error,
description: 'Error parsing SQS record',
messageId,
});

return null;
Expand Down Expand Up @@ -139,8 +141,13 @@ export const createHandler = ({

await Promise.all(
validatedRecords.map(async (validatedRecord: ValidatedRecord) => {
const { event, messageId } = validatedRecord;
const recordLogger = logger.child({
messageId,
messageReference: event.data.messageReference,
senderId: event.data.senderId,
});
try {
const { event } = validatedRecord;
const pdfBuffer = await getS3ObjectBufferFromUri(
event.data.letterUri,
);
Expand All @@ -152,20 +159,19 @@ export const createHandler = ({
const invalidAttachmentEvent =
generateInvalidAttachmentEvent(event);
validEvents.push(invalidAttachmentEvent);
logger.warn({
recordLogger.warn({
err: pdfError,
messageReference: event.data.messageReference,
reasonCode: 'DL_CLIV_002',
description: 'Failed to analyze PDF - invalid attachment format',
});
}
} catch (error: any) {
logger.warn({
recordLogger.warn({
err: error,
description: 'Failed processing message',
});
batchItemFailures.push({
itemIdentifier: validatedRecord.messageId,
itemIdentifier: messageId,
});
}
}),
Expand Down
8 changes: 7 additions & 1 deletion lambdas/print-sender-lambda/src/apis/sqs-trigger-lambda.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,12 @@ export const createHandler = ({

const messageReference =
sqsEventDetail?.data?.messageReference || 'not present';
const childLogger = logger.child({ messageReference });
const senderId = sqsEventDetail?.data?.senderId || 'not present';
const childLogger = logger.child({
messageId,
messageReference,
senderId,
});

validatePDFAnalysed(sqsEventDetail, childLogger);

Expand All @@ -44,6 +49,7 @@ export const createHandler = ({
logger.error({
err: error,
description: 'Error during SQS trigger handler',
messageId,
});

batchItemFailures.push({ itemIdentifier: messageId });
Expand Down
3 changes: 3 additions & 0 deletions lambdas/report-generator/src/apis/sqs-trigger-lambda.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ function validateRecord(
logger.error({
err: error,
description: 'Error parsing SQS record',
messageId,
});
return null;
}
Expand All @@ -71,6 +72,8 @@ async function processRecord(
logger.error({
err: error,
description: 'Error during SQS trigger handler',
messageId,
senderId: event.data.senderId,
});
batchItemFailures.push({ itemIdentifier: messageId });
return { result: { outcome: 'failed' }, item: event };
Expand Down
Loading
Loading