From 50733c90bdc9c2308d4aa073c2e1b99daff0bddd Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 11:40:01 +0100 Subject: [PATCH 01/17] feat(logger): add correlation ID extraction and search functionality --- packages/logger/package.json | 6 ++++- packages/logger/src/Logger.ts | 36 +++++++++++++++++++++++++ packages/logger/src/correlationId.ts | 11 ++++++++ packages/logger/src/middleware/middy.ts | 7 +++++ packages/logger/src/types/Logger.ts | 25 ++++++++++++----- packages/logger/src/types/index.ts | 6 +++++ 6 files changed, 84 insertions(+), 7 deletions(-) create mode 100644 packages/logger/src/correlationId.ts diff --git a/packages/logger/package.json b/packages/logger/package.json index 544314ce05..865f68db18 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -68,11 +68,15 @@ "@types/lodash.merge": "^4.6.9" }, "peerDependencies": { - "@middy/core": "4.x || 5.x || 6.x" + "@middy/core": "4.x || 5.x || 6.x", + "@aws-lambda-powertools/jmespath": "2.x" }, "peerDependenciesMeta": { "@middy/core": { "optional": true + }, + "@aws-lambda-powertools/jmespath": { + "optional": true } }, "files": [ diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index f39bb8ef0e..79a9b4da17 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -213,6 +213,11 @@ class Logger extends Utility implements LoggerInterface { */ #buffer?: CircularMap; + /** + * Search function for the correlation ID. + */ + #correlationIdSearchFn?: (expression: string, data: unknown) => unknown; + /** * Log level used by the current instance of Logger. * @@ -462,6 +467,9 @@ class Logger extends Utility implements LoggerInterface { loggerRef.refreshSampleRateCalculation(); loggerRef.addContext(context); loggerRef.logEventIfEnabled(event, options?.logEvent); + if (options?.correlationIdPath) { + loggerRef.setCorrelationIdFromPath(options?.correlationIdPath, event); + } try { return await originalMethod.apply(this, [event, context, callback]); @@ -1229,6 +1237,7 @@ class Logger extends Utility implements LoggerInterface { jsonReplacerFn, logRecordOrder, logBufferOptions, + correlationIdSearchFn, } = options; if (persistentLogAttributes && persistentKeys) { @@ -1255,6 +1264,7 @@ class Logger extends Utility implements LoggerInterface { this.setLogIndentation(); this.#jsonReplacerFn = jsonReplacerFn; this.#setLogBuffering(logBufferOptions); + this.#correlationIdSearchFn = correlationIdSearchFn; return this; } @@ -1407,6 +1417,32 @@ class Logger extends Utility implements LoggerInterface { logLevel <= this.#bufferConfig.bufferAtVerbosity ); } + + /** + * Extract the correlation ID from the event using the provided path and append it to the log attributes. + * @param correlationIdPath - The path to the correlation ID in the event object + * @param event - The event object + */ + public setCorrelationIdFromPath( + correlationIdPath: string, + event: unknown + ): void { + if (!this.#correlationIdSearchFn) { + this.warn( + 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' + ); + } else { + const correlationId = this.#correlationIdSearchFn( + correlationIdPath, + event + ); + if (correlationId) this.setCorrelationId(correlationId); + } + } + + public setCorrelationId(value: unknown): void { + this.appendKeys({ correlation_id: value }); + } } export { Logger }; diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts new file mode 100644 index 0000000000..93a5ebd842 --- /dev/null +++ b/packages/logger/src/correlationId.ts @@ -0,0 +1,11 @@ +import type { JSONObject } from '@aws-lambda-powertools/commons/types'; +import { search as JMESPathSearch } from '@aws-lambda-powertools/jmespath'; +import { PowertoolsFunctions } from '@aws-lambda-powertools/jmespath/functions'; + +const search = (expression: string, data: JSONObject) => { + JMESPathSearch(expression, data, { + customFunctions: new PowertoolsFunctions(), + }); +}; + +export { search }; diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index f85b1af9f8..e0776028ea 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -95,6 +95,13 @@ const injectLambdaContext = ( request.context, options ); + + if (options?.correlationIdPath) { + logger.setCorrelationIdFromPath( + options.correlationIdPath, + request.event + ); + } } }; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 01b7fbad20..ad4e981ffe 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -54,6 +54,11 @@ type InjectLambdaContextOptions = { * @default `false` */ flushBufferOnUncaughtError?: boolean; + + /** + * The path to the correlation ID in the event object, used to extract the correlation ID from the event object and add it to the log attributes. + */ + correlationIdPath?: string; }; /** @@ -217,13 +222,21 @@ type LogBufferOption = { }; }; +type CorrelationIdOption = { + /** + * The search function for the correlation ID. + */ + correlationIdSearchFn?: (expression: string, data: unknown) => unknown; +}; + /** * Options to configure the Logger. */ type ConstructorOptions = BaseConstructorOptions & (PersistentKeysOption | DeprecatedPersistentKeysOption) & (LogFormatterOption | LogRecordOrderOption) & - LogBufferOption; + LogBufferOption & + CorrelationIdOption; type LogItemMessage = string | LogAttributesWithMessage; type LogItemExtraInput = [Error | string] | LogAttributes[]; @@ -260,14 +273,14 @@ type LoggerInterface = { }; export type { + ConstructorOptions, + CustomJsonReplacerFn, Environment, + InjectLambdaContextOptions, LogAttributes, - LogLevel, LogFunction, LoggerInterface, - LogItemMessage, LogItemExtraInput, - ConstructorOptions, - InjectLambdaContextOptions, - CustomJsonReplacerFn, + LogItemMessage, + LogLevel, }; diff --git a/packages/logger/src/types/index.ts b/packages/logger/src/types/index.ts index 9544419a66..cdd04643a3 100644 --- a/packages/logger/src/types/index.ts +++ b/packages/logger/src/types/index.ts @@ -10,3 +10,9 @@ export type { LoggerInterface, } from './Logger.js'; export type { UnformattedAttributes } from './logKeys.js'; +export type { + JSONPrimitive, + JSONObject, + JSONArray, + JSONValue, +} from './json.js'; From f8a8cac26f52b194cec2f5181c3b0a8db63f5a19 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 12:51:17 +0100 Subject: [PATCH 02/17] test(logger): add unit tests for correlation ID handling in logger --- .../tests/unit/injectLambdaContext.test.ts | 139 ++++++++++++++++++ 1 file changed, 139 insertions(+) diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index 36c6d7c6fa..cd39abf92a 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -219,4 +219,143 @@ describe('Inject Lambda Context', () => { // Assess expect(refreshSpy).toHaveBeenCalledTimes(1); }); + describe('Correlation ID', () => { + const testEvent = { + headers: { + 'x-correlation-id': '12345-test-id', + }, + }; + + beforeEach(() => { + process.env = { + ...ENVIRONMENT_VARIABLES, + POWERTOOLS_DEV: 'true', + }; + vi.clearAllMocks(); + }); + + it('should set correlation ID when search function is provided', () => { + const searchFn = vi.fn().mockReturnValue('12345-test-id'); + + // Prepare + const logger = new Logger({ + correlationIdSearchFn: searchFn, + }); + + // Act + logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); + logger.info('Test message'); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Test message', + correlation_id: '12345-test-id', + }) + ); + }); + + it('should warn when no search function is provided', () => { + // Prepare + const logger = new Logger(); + const warnSpy = vi.spyOn(console, 'warn'); + + // Act + logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); + + // Assess + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining( + 'correlationIdPath is set but no search function was provided' + ) + ); + expect(console.info).not.toHaveBeenCalledWith( + expect.stringMatching(/correlation_id/) + ); + }); + + it('should not set correlation ID when search function returns undefined', () => { + // Prepare + const nullSearchFn = vi.fn().mockReturnValue(undefined); + const logger = new Logger({ correlationIdSearchFn: nullSearchFn }); + + // Act + logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); + logger.info('Test message'); + + // Assess + expect(nullSearchFn).toHaveBeenCalledWith( + 'headers.x-correlation-id', + testEvent + ); + expect(console.info).not.toHaveBeenCalledWith( + expect.stringMatching(/correlation_id/) + ); + }); + + it('should set correlation ID through middleware', async () => { + // Prepare + const searchFn = vi.fn().mockReturnValue('12345-test-id'); + const logger = new Logger({ correlationIdSearchFn: searchFn }); + const handler = middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers.x-correlation-id', + }) + ); + + // Act + await handler(testEvent, context); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Hello, world!', + correlation_id: '12345-test-id', + ...getContextLogEntries(), + }) + ); + }); + + it('should set correlation ID when using class decorator', async () => { + // Prepare + const searchFn = vi.fn().mockReturnValue('12345-test-id'); + const logger = new Logger({ correlationIdSearchFn: searchFn }); + + class TestHandler { + @logger.injectLambdaContext({ + correlationIdPath: 'headers.x-correlation-id', + }) + async handler(event: unknown, _context: Context): Promise { + logger.info('Hello from handler'); + } + } + + const lambda = new TestHandler(); + const handler = lambda.handler.bind(lambda); + + // Act + await handler(testEvent, context); + + // Assess + expect(searchFn).toHaveBeenCalledWith( + 'headers.x-correlation-id', + testEvent + ); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Hello from handler', + correlation_id: '12345-test-id', + ...getContextLogEntries(), + }) + ); + }); + }); }); From ad316587d8a3b3132348dad2aef3e23ea41e5e17 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 21:32:41 +0100 Subject: [PATCH 03/17] feat(logger): add correlation paths for various AWS services --- packages/logger/src/correlationId.ts | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts index 93a5ebd842..6e9b1aed12 100644 --- a/packages/logger/src/correlationId.ts +++ b/packages/logger/src/correlationId.ts @@ -8,4 +8,16 @@ const search = (expression: string, data: JSONObject) => { }); }; -export { search }; +const correlationPaths = { + API_GATEWAY_REST: 'requestContext.requestId', + API_GATEWAY_HTTP: 'requestContext.requestId', + APPSYNC_AUTHORIZER: 'requestContext.requestId', + APPSYNC_RESOLVER: 'request.headers."x-amzn-trace-id"', + APPLICATION_LOAD_BALANCER: 'headers."x-amzn-trace-id"', + EVENT_BRIDGE: 'id', + LAMBDA_FUNCTION_URL: 'requestContext.requestId', + S3_OBJECT_LAMBDA: 'xAmzRequestId', + VPC_LATTICE: 'headers."x-amzn-trace-id"', +}; + +export { correlationPaths, search }; From 4e8e2b3e82b5907b4d5f76b7ded6ed5d5fbb8747 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 21:35:15 +0100 Subject: [PATCH 04/17] feat(logger): export correlation paths and update exports in index --- packages/logger/src/index.ts | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index ae100eb930..94d8b30a96 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,4 +1,5 @@ -export { Logger } from './Logger.js'; +export { LogLevel, LogLevelThreshold } from './constants.js'; +export { correlationPaths } from './correlationId.js'; export { LogFormatter } from './formatter/LogFormatter.js'; export { LogItem } from './formatter/LogItem.js'; -export { LogLevel, LogLevelThreshold } from './constants.js'; +export { Logger } from './Logger.js'; From 61357ce0f77b728c12759bea8909f910fd8bd865 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 21:41:31 +0100 Subject: [PATCH 05/17] feat(logger): enhance correlation ID handling with getter and setter methods --- packages/logger/src/Logger.ts | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 79a9b4da17..da6c6f0b85 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -1423,7 +1423,7 @@ class Logger extends Utility implements LoggerInterface { * @param correlationIdPath - The path to the correlation ID in the event object * @param event - The event object */ - public setCorrelationIdFromPath( + protected setCorrelationIdFromPath( correlationIdPath: string, event: unknown ): void { @@ -1440,9 +1440,21 @@ class Logger extends Utility implements LoggerInterface { } } + /** + * Set the correlation ID in the log attributes. + * @param value - The value to set as the correlation ID + */ public setCorrelationId(value: unknown): void { this.appendKeys({ correlation_id: value }); } + + /** + * Get the correlation ID from the log attributes. + * @returns The correlation ID from the log attributes + */ + public getCorrelationId(): unknown { + return this.temporaryLogAttributes.correlation_id; + } } export { Logger }; From 59850ca4c985f6327fc9811833acbc85da5d105c Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 22:28:55 +0100 Subject: [PATCH 06/17] test(logger): remove unnecessary tests --- .../tests/unit/injectLambdaContext.test.ts | 84 +++++-------------- 1 file changed, 23 insertions(+), 61 deletions(-) diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index cd39abf92a..3951478590 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -234,67 +234,6 @@ describe('Inject Lambda Context', () => { vi.clearAllMocks(); }); - it('should set correlation ID when search function is provided', () => { - const searchFn = vi.fn().mockReturnValue('12345-test-id'); - - // Prepare - const logger = new Logger({ - correlationIdSearchFn: searchFn, - }); - - // Act - logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); - logger.info('Test message'); - - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Test message', - correlation_id: '12345-test-id', - }) - ); - }); - - it('should warn when no search function is provided', () => { - // Prepare - const logger = new Logger(); - const warnSpy = vi.spyOn(console, 'warn'); - - // Act - logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); - - // Assess - expect(warnSpy).toHaveBeenCalledWith( - expect.stringContaining( - 'correlationIdPath is set but no search function was provided' - ) - ); - expect(console.info).not.toHaveBeenCalledWith( - expect.stringMatching(/correlation_id/) - ); - }); - - it('should not set correlation ID when search function returns undefined', () => { - // Prepare - const nullSearchFn = vi.fn().mockReturnValue(undefined); - const logger = new Logger({ correlationIdSearchFn: nullSearchFn }); - - // Act - logger.setCorrelationIdFromPath('headers.x-correlation-id', testEvent); - logger.info('Test message'); - - // Assess - expect(nullSearchFn).toHaveBeenCalledWith( - 'headers.x-correlation-id', - testEvent - ); - expect(console.info).not.toHaveBeenCalledWith( - expect.stringMatching(/correlation_id/) - ); - }); - it('should set correlation ID through middleware', async () => { // Prepare const searchFn = vi.fn().mockReturnValue('12345-test-id'); @@ -357,5 +296,28 @@ describe('Inject Lambda Context', () => { }) ); }); + + it('should set correlation ID manually', () => { + // Prepare + const logger = new Logger(); + + // Act + logger.addContext(context); + logger.setCorrelationId('12345-test-id'); + logger.info('Hello, world!'); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Hello, world!', + correlation_id: '12345-test-id', + ...getContextLogEntries(), + }) + ); + + expect(logger.getCorrelationId()).toBe('12345-test-id'); + }); }); }); From 23a62c0687431352671ecabe5a50df4bac145f18 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 22:29:07 +0100 Subject: [PATCH 07/17] docs(logger): add documentation and examples for correlation ID handling --- docs/core/logger.md | 66 +++++++++++++++++++ .../snippets/logger/correlationIdDecorator.ts | 19 ++++++ .../snippets/logger/correlationIdLogger.ts | 6 ++ .../snippets/logger/correlationIdManual.ts | 16 +++++ .../snippets/logger/correlationIdMiddy.ts | 21 ++++++ .../snippets/logger/correlationIdOutput.json | 7 ++ .../snippets/logger/correlationIdPaths.ts | 19 ++++++ .../snippets/logger/correlationIdPayload.json | 5 ++ 8 files changed, 159 insertions(+) create mode 100644 examples/snippets/logger/correlationIdDecorator.ts create mode 100644 examples/snippets/logger/correlationIdLogger.ts create mode 100644 examples/snippets/logger/correlationIdManual.ts create mode 100644 examples/snippets/logger/correlationIdMiddy.ts create mode 100644 examples/snippets/logger/correlationIdOutput.json create mode 100644 examples/snippets/logger/correlationIdPaths.ts create mode 100644 examples/snippets/logger/correlationIdPayload.json diff --git a/docs/core/logger.md b/docs/core/logger.md index 523214a147..fb774793a8 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -207,6 +207,72 @@ When debugging in non-production environments, you can log the incoming event us Use `POWERTOOLS_LOGGER_LOG_EVENT` environment variable to enable or disable (`true`/`false`) this feature. When using Middy.js middleware or class method decorator, the `logEvent` option will take precedence over the environment variable. +### Setting a Correlation ID + +To gest started, install `@aws-lambda-powertools/jmespath` package and configure the search function for the correlationId: + +=== "Setup the Logger to use JMESPath search" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdLogger.ts" + ``` + + ???+ tip You can retrieve correlation IDs via `getCorrelationId` method. + +You can set a correlation ID using `correlationIdPath` parameter by passing a JMESPath expression, including our custom JMESPath functions or set it manually by calling `setCorrelationId` function. + +=== "Setting correlation ID manually" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdManual.ts" + ``` + +=== "Middy.js Middleware" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdMiddy.ts" + ``` + +=== "Decorator" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdDecorator.ts" + ``` + +=== "payload.json" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdPayload.json" + ``` + +=== "log-output.json" + + ```json hl_lines="6" + --8<-- "examples/snippets/logger/correlationIdOutput.json" + ``` + +To ease routine tasks like extracting correlation ID from popular event sources, we provide built-in JMESPath expressions. + +=== "Decorator" + + ```typescript + --8<-- "examples/snippets/logger/correlationIdPaths.ts" + ``` + +???+ note "Note: Any object key named with `-` must be escaped" + For example, **`request.headers."x-amzn-trace-id"`**. + +| Name | Expression | Description | +| ----------------------------- | ------------------------------------- | ------------------------------- | +| **API_GATEWAY_REST** | `'requestContext.requestId'` | API Gateway REST API request ID | +| **API_GATEWAY_HTTP** | `'requestContext.requestId'` | API Gateway HTTP API request ID | +| **APPSYNC_RESOLVER** | `'request.headers."x-amzn-trace-id"'` | AppSync X-Ray Trace ID | +| **APPLICATION_LOAD_BALANCER** | `'headers."x-amzn-trace-id"'` | ALB X-Ray Trace ID | +| **EVENT_BRIDGE** | `"id"` | EventBridge Event ID | +| **LAMBDA_FUNCTION_URL** | `'requestContext.requestId'` | Lambda Function URL request ID | +| **S3_OBJECT_LAMBDA** | `'xAmzRequestId'` | S3 Object trigger request ID | +| **VPC_LATTICE** | `'headers."x-amzn-trace-id'` | VPC Lattice X-Ray Trace ID | + ### Appending additional keys You can append additional keys using either mechanism: diff --git a/examples/snippets/logger/correlationIdDecorator.ts b/examples/snippets/logger/correlationIdDecorator.ts new file mode 100644 index 0000000000..943463e895 --- /dev/null +++ b/examples/snippets/logger/correlationIdDecorator.ts @@ -0,0 +1,19 @@ +import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; +import { search } from '@aws-lambda-powertools/jmespath'; +import { Logger } from '@aws-lambda-powertools/logger'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +class Lambda implements LambdaInterface { + @logger.injectLambdaContext({ + ccorrelationIdPath: 'headers.my_request_id_header', + }) + public async handler(_event: unknown, _context: unknown): Promise { + logger.info('This is an INFO log with some context'); + } +} + +const myFunction = new Lambda(); +export const handler = myFunction.handler.bind(myFunction); diff --git a/examples/snippets/logger/correlationIdLogger.ts b/examples/snippets/logger/correlationIdLogger.ts new file mode 100644 index 0000000000..e3e1f4ef4c --- /dev/null +++ b/examples/snippets/logger/correlationIdLogger.ts @@ -0,0 +1,6 @@ +import { search } from '@aws-lambda-powertools/jmespath'; +import { Logger } from '@aws-lambda-powertools/logger'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); diff --git a/examples/snippets/logger/correlationIdManual.ts b/examples/snippets/logger/correlationIdManual.ts new file mode 100644 index 0000000000..fd096f8642 --- /dev/null +++ b/examples/snippets/logger/correlationIdManual.ts @@ -0,0 +1,16 @@ +import { search } from '@aws-lambda-powertools/jmespath'; +import { Logger } from '@aws-lambda-powertools/logger'; +import type { APIGatewayProxyEvent, Context } from 'aws-lambda'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +export const handler = async ( + event: APIGatewayProxyEvent, + context: Context +): Promise => { + logger.setCorrelationId(event.requestContext.requestId); + + logger.info('This is an INFO log with some context'); +}; diff --git a/examples/snippets/logger/correlationIdMiddy.ts b/examples/snippets/logger/correlationIdMiddy.ts new file mode 100644 index 0000000000..c63bf9e36f --- /dev/null +++ b/examples/snippets/logger/correlationIdMiddy.ts @@ -0,0 +1,21 @@ +import { search } from '@aws-lambda-powertools/jmespath'; +import { Logger } from '@aws-lambda-powertools/logger'; +import { injectLambdaContext } from '@aws-lambda-powertools/logger/middleware'; +import middy from '@middy/core'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +const lambdaHandler = async ( + _event: unknown, + _context: unknown +): Promise => { + logger.info('This is an INFO log with some context'); +}; + +export const handler = middy(lambdaHandler).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers.my_request_id_header', + }) +); diff --git a/examples/snippets/logger/correlationIdOutput.json b/examples/snippets/logger/correlationIdOutput.json new file mode 100644 index 0000000000..b71e1984dc --- /dev/null +++ b/examples/snippets/logger/correlationIdOutput.json @@ -0,0 +1,7 @@ +{ + "level": "INFO", + "message": "This is an INFO log with some context", + "timestamp": "2021-05-03 11:47:12,494+0000", + "service": "payment", + "correlation_id": "correlation_id_value" +} diff --git a/examples/snippets/logger/correlationIdPaths.ts b/examples/snippets/logger/correlationIdPaths.ts new file mode 100644 index 0000000000..6e06307cf2 --- /dev/null +++ b/examples/snippets/logger/correlationIdPaths.ts @@ -0,0 +1,19 @@ +import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; +import { search } from '@aws-lambda-powertools/jmespath'; +import { Logger, correlationPaths } from '@aws-lambda-powertools/logger'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +class Lambda implements LambdaInterface { + @logger.injectLambdaContext({ + ccorrelationIdPath: correlationPaths.API_GATEWAY_REST, + }) + public async handler(_event: unknown, _context: unknown): Promise { + logger.info('This is an INFO log with some context'); + } +} + +const myFunction = new Lambda(); +export const handler = myFunction.handler.bind(myFunction); diff --git a/examples/snippets/logger/correlationIdPayload.json b/examples/snippets/logger/correlationIdPayload.json new file mode 100644 index 0000000000..ce2e8d8014 --- /dev/null +++ b/examples/snippets/logger/correlationIdPayload.json @@ -0,0 +1,5 @@ +{ + "headers": { + "my_request_id_header": "correlation_id_value" + } +} From f82f7b209ec2d4cc45458f45c71ce66263db4df6 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 23:19:44 +0100 Subject: [PATCH 08/17] fix(logger): correct return statement in search function and update correlation ID type definitions --- packages/logger/src/correlationId.ts | 2 +- packages/logger/src/types/Logger.ts | 7 +- .../tests/unit/injectLambdaContext.test.ts | 254 +++++++++++++++++- 3 files changed, 250 insertions(+), 13 deletions(-) diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts index 6e9b1aed12..be9ba1051a 100644 --- a/packages/logger/src/correlationId.ts +++ b/packages/logger/src/correlationId.ts @@ -3,7 +3,7 @@ import { search as JMESPathSearch } from '@aws-lambda-powertools/jmespath'; import { PowertoolsFunctions } from '@aws-lambda-powertools/jmespath/functions'; const search = (expression: string, data: JSONObject) => { - JMESPathSearch(expression, data, { + return JMESPathSearch(expression, data, { customFunctions: new PowertoolsFunctions(), }); }; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index ad4e981ffe..38b8c1a072 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -1,4 +1,7 @@ -import type { HandlerMethodDecorator } from '@aws-lambda-powertools/commons/types'; +import type { + HandlerMethodDecorator, + JSONObject, +} from '@aws-lambda-powertools/commons/types'; import type { Context } from 'aws-lambda'; import type { LogLevel as LogLevelList } from '../constants.js'; import type { LogFormatter } from '../formatter/LogFormatter.js'; @@ -226,7 +229,7 @@ type CorrelationIdOption = { /** * The search function for the correlation ID. */ - correlationIdSearchFn?: (expression: string, data: unknown) => unknown; + correlationIdSearchFn?: (expression: string, data: JSONObject) => unknown; }; /** diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index 3951478590..35911da2e5 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -3,6 +3,7 @@ import middy from '@middy/core'; import type { Context } from 'aws-lambda'; import { beforeEach, describe, expect, it, vi } from 'vitest'; import { Logger } from '../../src/Logger.js'; +import { search } from '../../src/correlationId.js'; import { injectLambdaContext } from '../../src/middleware/middy.js'; const event = { @@ -224,6 +225,10 @@ describe('Inject Lambda Context', () => { headers: { 'x-correlation-id': '12345-test-id', }, + requestContext: { + requestId: 'api-gateway-request-id', + }, + id: 'eventbridge-id', }; beforeEach(() => { @@ -236,13 +241,12 @@ describe('Inject Lambda Context', () => { it('should set correlation ID through middleware', async () => { // Prepare - const searchFn = vi.fn().mockReturnValue('12345-test-id'); - const logger = new Logger({ correlationIdSearchFn: searchFn }); + const logger = new Logger({ correlationIdSearchFn: search }); const handler = middy(async () => { logger.info('Hello, world!'); }).use( injectLambdaContext(logger, { - correlationIdPath: 'headers.x-correlation-id', + correlationIdPath: 'headers."x-correlation-id"', }) ); @@ -263,12 +267,11 @@ describe('Inject Lambda Context', () => { it('should set correlation ID when using class decorator', async () => { // Prepare - const searchFn = vi.fn().mockReturnValue('12345-test-id'); - const logger = new Logger({ correlationIdSearchFn: searchFn }); + const logger = new Logger({ correlationIdSearchFn: search }); class TestHandler { @logger.injectLambdaContext({ - correlationIdPath: 'headers.x-correlation-id', + correlationIdPath: 'headers."x-correlation-id"', }) async handler(event: unknown, _context: Context): Promise { logger.info('Hello from handler'); @@ -282,10 +285,6 @@ describe('Inject Lambda Context', () => { await handler(testEvent, context); // Assess - expect(searchFn).toHaveBeenCalledWith( - 'headers.x-correlation-id', - testEvent - ); expect(console.info).toHaveBeenCalledTimes(1); expect(console.info).toHaveLoggedNth( 1, @@ -319,5 +318,240 @@ describe('Inject Lambda Context', () => { expect(logger.getCorrelationId()).toBe('12345-test-id'); }); + + it('should warn when correlationIdPath is provided but no search function is available', async () => { + // Prepare + const logger = new Logger(); // No search function provided + const warnSpy = vi.spyOn(logger, 'warn'); + + // Act - Use middleware which will internally call setCorrelationIdFromPath + const handler = middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers.x-correlation-id', + }) + ); + + await handler(testEvent, context); + + // Assess + expect(warnSpy).toHaveBeenCalledWith( + 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' + ); + }); + + it('should not set correlation ID when search function returns falsy value', async () => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); + + // Act - Use middleware which will internally call setCorrelationIdFromPath + const handler = middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers."non-existent"', + }) + ); + + await handler(testEvent, context); + + // Assess + expect(logger.getCorrelationId()).toBeUndefined(); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.not.objectContaining({ + correlation_id: expect.anything(), + }) + ); + }); + + it('should propagate correlation ID to child loggers', () => { + // Prepare + const logger = new Logger(); + logger.setCorrelationId('parent-correlation-id'); + + // Act + const childLogger = logger.createChild(); + childLogger.info('Hello from child!'); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Hello from child!', + correlation_id: 'parent-correlation-id', + }) + ); + }); + + it('should allow using different types as correlation ID', () => { + // Prepare + const logger = new Logger(); + const numericId = 12345; + + // Act + logger.setCorrelationId(numericId); + logger.info('Using numeric ID'); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Using numeric ID', + correlation_id: numericId, + }) + ); + expect(logger.getCorrelationId()).toBe(numericId); + }); + + it('should handle complex objects as correlation ID', () => { + // Prepare + const logger = new Logger(); + const complexId = { requestId: 'abc123', timestamp: Date.now() }; + + // Act + logger.setCorrelationId(complexId); + logger.info('Using complex object ID'); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Using complex object ID', + correlation_id: complexId, + }) + ); + expect(logger.getCorrelationId()).toEqual(complexId); + }); + + it('should set correlation IDs across multiple logger instances with middleware', async () => { + // Prepare + const logger1 = new Logger({ correlationIdSearchFn: search }); + const logger2 = new Logger({ correlationIdSearchFn: search }); + + const handler = middy(async () => { + logger1.info('Log from first logger'); + logger2.info('Log from second logger'); + }).use( + injectLambdaContext([logger1, logger2], { + correlationIdPath: 'headers."x-correlation-id"', + }) + ); + + // Act + await handler(testEvent, context); + + // Assess + expect(console.info).toHaveBeenCalledTimes(2); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Log from first logger', + correlation_id: '12345-test-id', + }) + ); + expect(console.info).toHaveLoggedNth( + 2, + expect.objectContaining({ + message: 'Log from second logger', + correlation_id: '12345-test-id', + }) + ); + }); + + it('should work with both correlationIdPath and logEvent options together', async () => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); + const infoSpy = vi.spyOn(logger, 'info'); + + const handler = middy(async () => { + logger.info('Log with correlation ID'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers."x-correlation-id"', + logEvent: true, + }) + ); + + // Act + await handler(testEvent, context); + + // Assess + // First call should be for the event logging + expect(infoSpy).toHaveBeenNthCalledWith( + 1, + 'Lambda invocation event', + expect.objectContaining({ event: testEvent }) + ); + // Second call should be our actual log + expect(infoSpy).toHaveBeenNthCalledWith(2, 'Log with correlation ID'); + + // Check the log output includes correlation ID + expect(console.info).toHaveBeenCalledTimes(2); + expect(console.info).toHaveLoggedNth( + 2, + expect.objectContaining({ + message: 'Log with correlation ID', + correlation_id: '12345-test-id', + }) + ); + }); + + it('should use the API_GATEWAY_REST predefined path to extract correlation ID', async () => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); + const handler = middy(async () => { + logger.info('Using API Gateway request ID'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'requestContext.requestId', + }) + ); + + // Act + await handler(testEvent, context); + + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Using API Gateway request ID', + correlation_id: 'api-gateway-request-id', + }) + ); + }); + + it('should handle undefined correlation ID gracefully', async () => { + // Prepare + const searchFn = vi.fn().mockReturnValue(undefined); + const logger = new Logger({ correlationIdSearchFn: searchFn }); + + const handler = middy(async () => { + logger.info('No correlation ID available'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'non.existent.path', + }) + ); + + // Act + await handler(testEvent, context); + + // Assess + expect(searchFn).toHaveBeenCalledWith('non.existent.path', testEvent); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.not.objectContaining({ + correlation_id: expect.anything(), + }) + ); + }); }); }); From 6be9f4f7c0f1760e5b7b2e6bdf77e3aad3a12f00 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Thu, 13 Mar 2025 23:25:35 +0100 Subject: [PATCH 09/17] refactor(logger): update correlation ID imports and restructure logger initialization --- examples/snippets/logger/correlationIdDecorator.ts | 2 +- examples/snippets/logger/correlationIdLogger.ts | 2 +- examples/snippets/logger/correlationIdManual.ts | 5 +---- examples/snippets/logger/correlationIdMiddy.ts | 2 +- examples/snippets/logger/correlationIdPaths.ts | 7 +++++-- packages/logger/package.json | 8 +++++--- packages/logger/src/index.ts | 1 - 7 files changed, 14 insertions(+), 13 deletions(-) diff --git a/examples/snippets/logger/correlationIdDecorator.ts b/examples/snippets/logger/correlationIdDecorator.ts index 943463e895..67ba0e3e8e 100644 --- a/examples/snippets/logger/correlationIdDecorator.ts +++ b/examples/snippets/logger/correlationIdDecorator.ts @@ -1,6 +1,6 @@ import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; -import { search } from '@aws-lambda-powertools/jmespath'; import { Logger } from '@aws-lambda-powertools/logger'; +import { search } from '@aws-lambda-powertools/logger/correlationId'; const logger = new Logger({ correlationIdSearchFn: search, diff --git a/examples/snippets/logger/correlationIdLogger.ts b/examples/snippets/logger/correlationIdLogger.ts index e3e1f4ef4c..3c003fb0a5 100644 --- a/examples/snippets/logger/correlationIdLogger.ts +++ b/examples/snippets/logger/correlationIdLogger.ts @@ -1,5 +1,5 @@ -import { search } from '@aws-lambda-powertools/jmespath'; import { Logger } from '@aws-lambda-powertools/logger'; +import { search } from '@aws-lambda-powertools/logger/correlationId'; const logger = new Logger({ correlationIdSearchFn: search, diff --git a/examples/snippets/logger/correlationIdManual.ts b/examples/snippets/logger/correlationIdManual.ts index fd096f8642..527e700c25 100644 --- a/examples/snippets/logger/correlationIdManual.ts +++ b/examples/snippets/logger/correlationIdManual.ts @@ -1,10 +1,7 @@ -import { search } from '@aws-lambda-powertools/jmespath'; import { Logger } from '@aws-lambda-powertools/logger'; import type { APIGatewayProxyEvent, Context } from 'aws-lambda'; -const logger = new Logger({ - correlationIdSearchFn: search, -}); +const logger = new Logger(); export const handler = async ( event: APIGatewayProxyEvent, diff --git a/examples/snippets/logger/correlationIdMiddy.ts b/examples/snippets/logger/correlationIdMiddy.ts index c63bf9e36f..9258177a43 100644 --- a/examples/snippets/logger/correlationIdMiddy.ts +++ b/examples/snippets/logger/correlationIdMiddy.ts @@ -1,5 +1,5 @@ -import { search } from '@aws-lambda-powertools/jmespath'; import { Logger } from '@aws-lambda-powertools/logger'; +import { search } from '@aws-lambda-powertools/logger/correlationId'; import { injectLambdaContext } from '@aws-lambda-powertools/logger/middleware'; import middy from '@middy/core'; diff --git a/examples/snippets/logger/correlationIdPaths.ts b/examples/snippets/logger/correlationIdPaths.ts index 6e06307cf2..73a50b62c1 100644 --- a/examples/snippets/logger/correlationIdPaths.ts +++ b/examples/snippets/logger/correlationIdPaths.ts @@ -1,6 +1,9 @@ import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; -import { search } from '@aws-lambda-powertools/jmespath'; -import { Logger, correlationPaths } from '@aws-lambda-powertools/logger'; +import { Logger } from '@aws-lambda-powertools/logger'; +import { + correlationPaths, + search, +} from '@aws-lambda-powertools/logger/correlationId'; const logger = new Logger({ correlationIdSearchFn: search, diff --git a/packages/logger/package.json b/packages/logger/package.json index 865f68db18..b953f1a73f 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -47,6 +47,10 @@ "./types": { "import": "./lib/esm/types/index.js", "require": "./lib/cjs/types/index.js" + }, + "./correlationId": { + "import": "./lib/esm/correlationId.js", + "require": "./lib/cjs//correlationId.js" } }, "typesVersions": { @@ -79,9 +83,7 @@ "optional": true } }, - "files": [ - "lib" - ], + "files": ["lib"], "repository": { "type": "git", "url": "git+https://github.com/aws-powertools/powertools-lambda-typescript.git" diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 94d8b30a96..f736cbff35 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,5 +1,4 @@ export { LogLevel, LogLevelThreshold } from './constants.js'; -export { correlationPaths } from './correlationId.js'; export { LogFormatter } from './formatter/LogFormatter.js'; export { LogItem } from './formatter/LogItem.js'; export { Logger } from './Logger.js'; From 452ad79503c711d6d56f1c901ee9e502cf2e30d9 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 09:59:53 +0100 Subject: [PATCH 10/17] test(logger): fix tests after merge issues --- .../tests/unit/injectLambdaContext.test.ts | 25 +------------------ 1 file changed, 1 insertion(+), 24 deletions(-) diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index 4b36af30b4..d18c473300 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -239,30 +239,8 @@ describe('Inject Lambda Context', () => { }) ); } - - const lambda = new Lambda(); - // Act - await lambda.handler({}, {} as Context); - - // Assess - expect(refreshSpy).toHaveBeenCalledTimes(1); - }); - - it('refreshes sample rate calculation before each invocation using middleware for warm start only', async () => { - // Prepare - const logger = new Logger({ sampleRateValue: 0.5 }); - const refreshSpy = vi.spyOn(logger, 'refreshSampleRateCalculation'); - - const handler = middy(async () => { - logger.info('Hello, world!'); - }).use(injectLambdaContext(logger)); - - // Act - await handler(event, context); + ); - // Assess - expect(refreshSpy).toHaveBeenCalledTimes(1); - }); describe('Correlation ID', () => { const testEvent = { headers: { @@ -597,5 +575,4 @@ describe('Inject Lambda Context', () => { ); }); }); - ); }); From 667ae6c0249551716f513be45db7a6ae08ef3e7c Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 10:15:17 +0100 Subject: [PATCH 11/17] chore: clean up and fix signatures --- packages/logger/src/Logger.ts | 7 ++++--- packages/logger/src/middleware/middy.ts | 3 ++- packages/logger/src/types/index.ts | 18 ++++++------------ 3 files changed, 12 insertions(+), 16 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 4b9916b0a1..0164276392 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -4,6 +4,7 @@ import { Utility, isNullOrUndefined } from '@aws-lambda-powertools/commons'; import type { AsyncHandler, HandlerMethodDecorator, + JSONObject, SyncHandler, } from '@aws-lambda-powertools/commons/types'; import type { Context, Handler } from 'aws-lambda'; @@ -218,7 +219,7 @@ class Logger extends Utility implements LoggerInterface { /** * Search function for the correlation ID. */ - #correlationIdSearchFn?: (expression: string, data: unknown) => unknown; + #correlationIdSearchFn?: (expression: string, data: JSONObject) => unknown; /** * The debug sampling rate configuration. @@ -1455,9 +1456,9 @@ class Logger extends Utility implements LoggerInterface { * @param correlationIdPath - The path to the correlation ID in the event object * @param event - The event object */ - protected setCorrelationIdFromPath( + public setCorrelationIdFromPath( correlationIdPath: string, - event: unknown + event: JSONObject ): void { if (!this.#correlationIdSearchFn) { this.warn( diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index e0776028ea..006280e568 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -1,5 +1,6 @@ import { LOGGER_KEY } from '@aws-lambda-powertools/commons'; import type { + JSONObject, MiddlewareLikeObj, MiddyLikeRequest, } from '@aws-lambda-powertools/commons/types'; @@ -99,7 +100,7 @@ const injectLambdaContext = ( if (options?.correlationIdPath) { logger.setCorrelationIdFromPath( options.correlationIdPath, - request.event + request.event as JSONObject ); } } diff --git a/packages/logger/src/types/index.ts b/packages/logger/src/types/index.ts index cdd04643a3..30a0e6a1d7 100644 --- a/packages/logger/src/types/index.ts +++ b/packages/logger/src/types/index.ts @@ -1,18 +1,12 @@ export type { - Environment, - LogAttributes, - LogLevel, - LogItemMessage, - LogItemExtraInput, ConstructorOptions, - InjectLambdaContextOptions, CustomJsonReplacerFn, + Environment, + InjectLambdaContextOptions, + LogAttributes, LoggerInterface, + LogItemExtraInput, + LogItemMessage, + LogLevel, } from './Logger.js'; export type { UnformattedAttributes } from './logKeys.js'; -export type { - JSONPrimitive, - JSONObject, - JSONArray, - JSONValue, -} from './json.js'; From 2daf9fa568adf99e626213c12e0123d05c773bdf Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 10:19:11 +0100 Subject: [PATCH 12/17] docs(logger): fix typo in examples --- examples/snippets/logger/correlationIdDecorator.ts | 2 +- examples/snippets/logger/correlationIdPaths.ts | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/examples/snippets/logger/correlationIdDecorator.ts b/examples/snippets/logger/correlationIdDecorator.ts index 67ba0e3e8e..f4b93fb7f4 100644 --- a/examples/snippets/logger/correlationIdDecorator.ts +++ b/examples/snippets/logger/correlationIdDecorator.ts @@ -8,7 +8,7 @@ const logger = new Logger({ class Lambda implements LambdaInterface { @logger.injectLambdaContext({ - ccorrelationIdPath: 'headers.my_request_id_header', + correlationIdPath: 'headers.my_request_id_header', }) public async handler(_event: unknown, _context: unknown): Promise { logger.info('This is an INFO log with some context'); diff --git a/examples/snippets/logger/correlationIdPaths.ts b/examples/snippets/logger/correlationIdPaths.ts index 73a50b62c1..b6cb3f500e 100644 --- a/examples/snippets/logger/correlationIdPaths.ts +++ b/examples/snippets/logger/correlationIdPaths.ts @@ -11,7 +11,7 @@ const logger = new Logger({ class Lambda implements LambdaInterface { @logger.injectLambdaContext({ - ccorrelationIdPath: correlationPaths.API_GATEWAY_REST, + correlationIdPath: correlationPaths.API_GATEWAY_REST, }) public async handler(_event: unknown, _context: unknown): Promise { logger.info('This is an INFO log with some context'); From c5b471a7b3827658002b8e32dd7a7f857e3598bb Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 10:27:27 +0100 Subject: [PATCH 13/17] test(logger): refactor tests --- .../tests/unit/injectLambdaContext.test.ts | 72 +++++++++---------- 1 file changed, 33 insertions(+), 39 deletions(-) diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index d18c473300..abf96d7739 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -260,16 +260,40 @@ describe('Inject Lambda Context', () => { vi.clearAllMocks(); }); - it('should set correlation ID through middleware', async () => { + it.each([ + { + case: 'middleware', + getHandler: (logger: Logger) => + middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers."x-correlation-id"', + }) + ), + }, + { + case: 'decorator', + getHandler: (logger: Logger) => { + class Lambda { + @logger.injectLambdaContext({ + correlationIdPath: 'headers."x-correlation-id"', + }) + public async handler( + _event: unknown, + _context: Context + ): Promise { + logger.info('Hello, world!'); + } + } + const lambda = new Lambda(); + return lambda.handler.bind(lambda); + }, + }, + ])('should set correlation ID through $case', async ({ getHandler }) => { // Prepare const logger = new Logger({ correlationIdSearchFn: search }); - const handler = middy(async () => { - logger.info('Hello, world!'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers."x-correlation-id"', - }) - ); + const handler = getHandler(logger); // Act await handler(testEvent, context); @@ -284,37 +308,7 @@ describe('Inject Lambda Context', () => { ...getContextLogEntries(), }) ); - }); - - it('should set correlation ID when using class decorator', async () => { - // Prepare - const logger = new Logger({ correlationIdSearchFn: search }); - - class TestHandler { - @logger.injectLambdaContext({ - correlationIdPath: 'headers."x-correlation-id"', - }) - async handler(event: unknown, _context: Context): Promise { - logger.info('Hello from handler'); - } - } - - const lambda = new TestHandler(); - const handler = lambda.handler.bind(lambda); - - // Act - await handler(testEvent, context); - - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Hello from handler', - correlation_id: '12345-test-id', - ...getContextLogEntries(), - }) - ); + expect(logger.getCorrelationId()).toBe('12345-test-id'); }); it('should set correlation ID manually', () => { From c588056fde288958e9f42898681155488cec6c8a Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 11:36:46 +0100 Subject: [PATCH 14/17] chore: addressed PR comments --- docs/core/logger.md | 4 +- packages/logger/package.json | 2 +- packages/logger/src/Logger.ts | 59 ++- packages/logger/src/correlationId.ts | 44 +- packages/logger/src/middleware/middy.ts | 6 +- packages/logger/src/types/Logger.ts | 8 +- .../tests/unit/injectLambdaContext.test.ts | 474 +++++++----------- 7 files changed, 260 insertions(+), 337 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index cd355e1958..7218ba38e7 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -217,7 +217,8 @@ To gest started, install `@aws-lambda-powertools/jmespath` package and configure --8<-- "examples/snippets/logger/correlationIdLogger.ts" ``` - ???+ tip You can retrieve correlation IDs via `getCorrelationId` method. +???+ tip + You can retrieve correlation IDs via `getCorrelationId` method. You can set a correlation ID using `correlationIdPath` parameter by passing a JMESPath expression, including our custom JMESPath functions or set it manually by calling `setCorrelationId` function. @@ -266,6 +267,7 @@ To ease routine tasks like extracting correlation ID from popular event sources, | ----------------------------- | ------------------------------------- | ------------------------------- | | **API_GATEWAY_REST** | `'requestContext.requestId'` | API Gateway REST API request ID | | **API_GATEWAY_HTTP** | `'requestContext.requestId'` | API Gateway HTTP API request ID | +| **APPSYNC_AUTHORIZER** | `'requestContext.requestId'` | AppSync resolver request ID | | **APPSYNC_RESOLVER** | `'request.headers."x-amzn-trace-id"'` | AppSync X-Ray Trace ID | | **APPLICATION_LOAD_BALANCER** | `'headers."x-amzn-trace-id"'` | ALB X-Ray Trace ID | | **EVENT_BRIDGE** | `"id"` | EventBridge Event ID | diff --git a/packages/logger/package.json b/packages/logger/package.json index b953f1a73f..acf8b56457 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -50,7 +50,7 @@ }, "./correlationId": { "import": "./lib/esm/correlationId.js", - "require": "./lib/cjs//correlationId.js" + "require": "./lib/cjs/correlationId.js" } }, "typesVersions": { diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 0164276392..15ee5d13c1 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -4,7 +4,6 @@ import { Utility, isNullOrUndefined } from '@aws-lambda-powertools/commons'; import type { AsyncHandler, HandlerMethodDecorator, - JSONObject, SyncHandler, } from '@aws-lambda-powertools/commons/types'; import type { Context, Handler } from 'aws-lambda'; @@ -219,7 +218,7 @@ class Logger extends Utility implements LoggerInterface { /** * Search function for the correlation ID. */ - #correlationIdSearchFn?: (expression: string, data: JSONObject) => unknown; + #correlationIdSearchFn?: (expression: string, data: unknown) => unknown; /** * The debug sampling rate configuration. @@ -332,6 +331,7 @@ class Logger extends Utility implements LoggerInterface { environment: this.powertoolsLogData.environment, persistentLogAttributes: this.persistentLogAttributes, jsonReplacerFn: this.#jsonReplacerFn, + correlationIdSearchFn: this.#correlationIdSearchFn, ...(this.#bufferConfig.enabled && { logBufferOptions: { maxBytes: this.#bufferConfig.maxBytes, @@ -487,7 +487,7 @@ class Logger extends Utility implements LoggerInterface { loggerRef.addContext(context); loggerRef.logEventIfEnabled(event, options?.logEvent); if (options?.correlationIdPath) { - loggerRef.setCorrelationIdFromPath(options?.correlationIdPath, event); + loggerRef.setCorrelationId(event, options?.correlationIdPath); } try { @@ -1452,32 +1452,45 @@ class Logger extends Utility implements LoggerInterface { } /** - * Extract the correlation ID from the event using the provided path and append it to the log attributes. - * @param correlationIdPath - The path to the correlation ID in the event object - * @param event - The event object + * Set the correlation ID for the log item. + * This method can be used to set the correlation ID for the log item or to search for the correlation ID in the event. + * + * @example + * ```typescript + * import { Logger } from '@aws-lambda-powertools/logger'; + * + * const logger = new Logger(); + * logger.setCorrelationId('my-correlation-id'); // sets the correlation ID directly with the first argument as value + * ``` + * + * ```typescript + * import { Logger } from '@aws-lambda-powertools/logger'; + * import { search } from '@aws-lambda-powertools/logger/correlationId'; + * + * const logger = new Logger({ correlationIdSearchFn: search }); + * logger.setCorrelationId(event, 'requestContext.requestId'); // sets the correlation ID from the event using JMSPath expression + * + * + * @param value - The value to set as the correlation ID or the event to search for the correlation ID + * @param correlationIdPath - The path to search for the correlation ID in the event, if not set value is used directly */ - public setCorrelationIdFromPath( - correlationIdPath: string, - event: JSONObject - ): void { - if (!this.#correlationIdSearchFn) { - this.warn( - 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' - ); - } else { + public setCorrelationId(value: unknown, correlationIdPath?: string): void { + if (typeof correlationIdPath === 'string') { + if (!this.#correlationIdSearchFn) { + this.warn( + 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' + ); + return; + } const correlationId = this.#correlationIdSearchFn( correlationIdPath, - event + value ); - if (correlationId) this.setCorrelationId(correlationId); + if (correlationId) this.appendKeys({ correlation_id: correlationId }); + return; } - } - /** - * Set the correlation ID in the log attributes. - * @param value - The value to set as the correlation ID - */ - public setCorrelationId(value: unknown): void { + // If no correlationIdPath is provided, set the correlation ID directly this.appendKeys({ correlation_id: value }); } diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts index be9ba1051a..20bd7a363f 100644 --- a/packages/logger/src/correlationId.ts +++ b/packages/logger/src/correlationId.ts @@ -2,22 +2,60 @@ import type { JSONObject } from '@aws-lambda-powertools/commons/types'; import { search as JMESPathSearch } from '@aws-lambda-powertools/jmespath'; import { PowertoolsFunctions } from '@aws-lambda-powertools/jmespath/functions'; -const search = (expression: string, data: JSONObject) => { - return JMESPathSearch(expression, data, { +/** + * This function is used to search for a correlation ID in the event data and is a wrapper + * around the JMESPath search function. It allows you to specify a JMESPath expression + * to extract the correlation ID from the event data. + * @param expression - The JMESPath expression to use for searching the correlation ID. + * @param data - The event data to search in. + * @returns - The correlation ID extracted from the event data. + */ +const search = (expression: string, data: unknown) => { + return JMESPathSearch(expression, data as JSONObject, { customFunctions: new PowertoolsFunctions(), }); }; +/** + * The correlationPaths object contains the JMESPath expressions for extracting the correlation ID for various AWS services. + */ const correlationPaths = { + /** + * API Gateway REST API request ID + */ API_GATEWAY_REST: 'requestContext.requestId', + /** + * API Gateway HTTP API request ID + */ API_GATEWAY_HTTP: 'requestContext.requestId', + /** + * AppSync API request ID + */ APPSYNC_AUTHORIZER: 'requestContext.requestId', + /** + * AppSync resolver X-Ray trace ID + */ APPSYNC_RESOLVER: 'request.headers."x-amzn-trace-id"', + /** + * ALB X-Ray trace ID + */ APPLICATION_LOAD_BALANCER: 'headers."x-amzn-trace-id"', + /** + * EventBridge event ID + */ EVENT_BRIDGE: 'id', + /** + * Lambda Function URL request ID + */ LAMBDA_FUNCTION_URL: 'requestContext.requestId', + /** + * S3 Object trigger request ID + */ S3_OBJECT_LAMBDA: 'xAmzRequestId', + /** + * VPC Lattice X-Ray trace ID + */ VPC_LATTICE: 'headers."x-amzn-trace-id"', -}; +} as const; export { correlationPaths, search }; diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index 006280e568..eeaef4fd49 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -1,6 +1,5 @@ import { LOGGER_KEY } from '@aws-lambda-powertools/commons'; import type { - JSONObject, MiddlewareLikeObj, MiddyLikeRequest, } from '@aws-lambda-powertools/commons/types'; @@ -98,10 +97,7 @@ const injectLambdaContext = ( ); if (options?.correlationIdPath) { - logger.setCorrelationIdFromPath( - options.correlationIdPath, - request.event as JSONObject - ); + logger.setCorrelationId(request.event, options.correlationIdPath); } } }; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 38b8c1a072..e127f9441d 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -1,7 +1,4 @@ -import type { - HandlerMethodDecorator, - JSONObject, -} from '@aws-lambda-powertools/commons/types'; +import type { HandlerMethodDecorator } from '@aws-lambda-powertools/commons/types'; import type { Context } from 'aws-lambda'; import type { LogLevel as LogLevelList } from '../constants.js'; import type { LogFormatter } from '../formatter/LogFormatter.js'; @@ -229,7 +226,7 @@ type CorrelationIdOption = { /** * The search function for the correlation ID. */ - correlationIdSearchFn?: (expression: string, data: JSONObject) => unknown; + correlationIdSearchFn?: (expression: string, data: unknown) => unknown; }; /** @@ -268,6 +265,7 @@ type LoggerInterface = { removeKeys(keys?: string[]): void; removePersistentLogAttributes(keys?: string[]): void; resetKeys(): void; + setCorrelationId(value: unknown, correlationIdPath?: string): void; setLogLevel(logLevel: LogLevel): void; setPersistentLogAttributes(attributes?: LogAttributes): void; shouldLogEvent(overwriteValue?: boolean): boolean; diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index abf96d7739..cdd8079e98 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -241,332 +241,208 @@ describe('Inject Lambda Context', () => { } ); - describe('Correlation ID', () => { + it.each([ + { + case: 'middleware', + getHandler: (logger: Logger) => + middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers."x-correlation-id"', + }) + ), + }, + { + case: 'decorator', + getHandler: (logger: Logger) => { + class Lambda { + @logger.injectLambdaContext({ + correlationIdPath: 'headers."x-correlation-id"', + }) + public async handler( + _event: unknown, + _context: Context + ): Promise { + logger.info('Hello, world!'); + } + } + const lambda = new Lambda(); + return lambda.handler.bind(lambda); + }, + }, + ])('sets correlation ID through $case', async ({ getHandler }) => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); + const handler = getHandler(logger); const testEvent = { headers: { 'x-correlation-id': '12345-test-id', }, - requestContext: { - requestId: 'api-gateway-request-id', - }, - id: 'eventbridge-id', }; - beforeEach(() => { - process.env = { - ...ENVIRONMENT_VARIABLES, - POWERTOOLS_DEV: 'true', - }; - vi.clearAllMocks(); - }); - - it.each([ - { - case: 'middleware', - getHandler: (logger: Logger) => - middy(async () => { - logger.info('Hello, world!'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers."x-correlation-id"', - }) - ), - }, - { - case: 'decorator', - getHandler: (logger: Logger) => { - class Lambda { - @logger.injectLambdaContext({ - correlationIdPath: 'headers."x-correlation-id"', - }) - public async handler( - _event: unknown, - _context: Context - ): Promise { - logger.info('Hello, world!'); - } - } - const lambda = new Lambda(); - return lambda.handler.bind(lambda); - }, - }, - ])('should set correlation ID through $case', async ({ getHandler }) => { - // Prepare - const logger = new Logger({ correlationIdSearchFn: search }); - const handler = getHandler(logger); - - // Act - await handler(testEvent, context); - - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Hello, world!', - correlation_id: '12345-test-id', - ...getContextLogEntries(), - }) - ); - expect(logger.getCorrelationId()).toBe('12345-test-id'); - }); + // Act + await handler(testEvent, context); - it('should set correlation ID manually', () => { - // Prepare - const logger = new Logger(); + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Hello, world!', + correlation_id: '12345-test-id', + ...getContextLogEntries(), + }) + ); + expect(logger.getCorrelationId()).toBe('12345-test-id'); + }); - // Act - logger.addContext(context); - logger.setCorrelationId('12345-test-id'); + it('warns when correlationIdPath is provided but no search function is available', async () => { + // Prepare + const logger = new Logger(); // No search function provided + const warnSpy = vi.spyOn(logger, 'warn'); + const testEvent = { + headers: { + 'x-correlation-id': '12345-test-id', + }, + }; + // Act - Use middleware which will internally call setCorrelationIdFromPath + const handler = middy(async () => { logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers.x-correlation-id', + }) + ); - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Hello, world!', - correlation_id: '12345-test-id', - ...getContextLogEntries(), - }) - ); - - expect(logger.getCorrelationId()).toBe('12345-test-id'); - }); - - it('should warn when correlationIdPath is provided but no search function is available', async () => { - // Prepare - const logger = new Logger(); // No search function provided - const warnSpy = vi.spyOn(logger, 'warn'); - - // Act - Use middleware which will internally call setCorrelationIdFromPath - const handler = middy(async () => { - logger.info('Hello, world!'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers.x-correlation-id', - }) - ); - - await handler(testEvent, context); - - // Assess - expect(warnSpy).toHaveBeenCalledWith( - 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' - ); - }); - - it('should not set correlation ID when search function returns falsy value', async () => { - // Prepare - const logger = new Logger({ correlationIdSearchFn: search }); - - // Act - Use middleware which will internally call setCorrelationIdFromPath - const handler = middy(async () => { - logger.info('Hello, world!'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers."non-existent"', - }) - ); - - await handler(testEvent, context); - - // Assess - expect(logger.getCorrelationId()).toBeUndefined(); - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.not.objectContaining({ - correlation_id: expect.anything(), - }) - ); - }); - - it('should propagate correlation ID to child loggers', () => { - // Prepare - const logger = new Logger(); - logger.setCorrelationId('parent-correlation-id'); - - // Act - const childLogger = logger.createChild(); - childLogger.info('Hello from child!'); - - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Hello from child!', - correlation_id: 'parent-correlation-id', - }) - ); - }); - - it('should allow using different types as correlation ID', () => { - // Prepare - const logger = new Logger(); - const numericId = 12345; + await handler(testEvent, context); - // Act - logger.setCorrelationId(numericId); - logger.info('Using numeric ID'); + // Assess + expect(warnSpy).toHaveBeenCalledWith( + 'correlationIdPath is set but no search function was provided. The correlation ID will not be added to the log attributes.' + ); + }); - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Using numeric ID', - correlation_id: numericId, - }) - ); - expect(logger.getCorrelationId()).toBe(numericId); - }); + it('does not set correlation ID when search function returns falsy value', async () => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); - it('should handle complex objects as correlation ID', () => { - // Prepare - const logger = new Logger(); - const complexId = { requestId: 'abc123', timestamp: Date.now() }; + // Act - Use middleware which will internally call setCorrelationIdFromPath + const handler = middy(async () => { + logger.info('Hello, world!'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'headers."non-existent"', + }) + ); - // Act - logger.setCorrelationId(complexId); - logger.info('Using complex object ID'); + await handler({ foo: 'bar' }, context); - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Using complex object ID', - correlation_id: complexId, - }) - ); - expect(logger.getCorrelationId()).toEqual(complexId); - }); + // Assess + expect(logger.getCorrelationId()).toBeUndefined(); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.not.objectContaining({ + correlation_id: expect.anything(), + }) + ); + }); - it('should set correlation IDs across multiple logger instances with middleware', async () => { - // Prepare - const logger1 = new Logger({ correlationIdSearchFn: search }); - const logger2 = new Logger({ correlationIdSearchFn: search }); - - const handler = middy(async () => { - logger1.info('Log from first logger'); - logger2.info('Log from second logger'); - }).use( - injectLambdaContext([logger1, logger2], { - correlationIdPath: 'headers."x-correlation-id"', - }) - ); + it('propagates search function to child loggers', () => { + // Prepare + const mockSearch = vi.fn().mockReturnValue('found-id'); + const logger = new Logger({ correlationIdSearchFn: mockSearch }); - // Act - await handler(testEvent, context); + // Act + const childLogger = logger.createChild(); + childLogger.setCorrelationId({ some: 'event' }, 'some.path'); - // Assess - expect(console.info).toHaveBeenCalledTimes(2); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Log from first logger', - correlation_id: '12345-test-id', - }) - ); - expect(console.info).toHaveLoggedNth( - 2, - expect.objectContaining({ - message: 'Log from second logger', - correlation_id: '12345-test-id', - }) - ); - }); + // Assess + expect(mockSearch).toHaveBeenCalledWith('some.path', { some: 'event' }); + expect(childLogger.getCorrelationId()).toBe('found-id'); + }); - it('should work with both correlationIdPath and logEvent options together', async () => { - // Prepare - const logger = new Logger({ correlationIdSearchFn: search }); - const infoSpy = vi.spyOn(logger, 'info'); - - const handler = middy(async () => { - logger.info('Log with correlation ID'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers."x-correlation-id"', - logEvent: true, - }) - ); + it('allows using different types as correlation ID', () => { + // Prepare + const logger = new Logger(); + const numericId = 12345; - // Act - await handler(testEvent, context); + // Act + logger.setCorrelationId(numericId); + logger.info('Using numeric ID'); - // Assess - // First call should be for the event logging - expect(infoSpy).toHaveBeenNthCalledWith( - 1, - 'Lambda invocation event', - expect.objectContaining({ event: testEvent }) - ); - // Second call should be our actual log - expect(infoSpy).toHaveBeenNthCalledWith(2, 'Log with correlation ID'); + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Using numeric ID', + correlation_id: numericId, + }) + ); + expect(logger.getCorrelationId()).toBe(numericId); + }); - // Check the log output includes correlation ID - expect(console.info).toHaveBeenCalledTimes(2); - expect(console.info).toHaveLoggedNth( - 2, - expect.objectContaining({ - message: 'Log with correlation ID', - correlation_id: '12345-test-id', - }) - ); - }); + it('uses the API_GATEWAY_REST predefined path to extract correlation ID', async () => { + // Prepare + const logger = new Logger({ correlationIdSearchFn: search }); + const handler = middy(async () => { + logger.info('Using API Gateway request ID'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'requestContext.requestId', + }) + ); + const testEvent = { + requestContext: { + requestId: 'api-gateway-request-id', + }, + }; - it('should use the API_GATEWAY_REST predefined path to extract correlation ID', async () => { - // Prepare - const logger = new Logger({ correlationIdSearchFn: search }); - const handler = middy(async () => { - logger.info('Using API Gateway request ID'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'requestContext.requestId', - }) - ); + // Act + await handler(testEvent, context); - // Act - await handler(testEvent, context); + // Assess + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.objectContaining({ + message: 'Using API Gateway request ID', + correlation_id: 'api-gateway-request-id', + }) + ); + }); - // Assess - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.objectContaining({ - message: 'Using API Gateway request ID', - correlation_id: 'api-gateway-request-id', - }) - ); - }); + it('handles undefined correlation ID gracefully', async () => { + // Prepare + const searchFn = vi.fn().mockReturnValue(undefined); + const logger = new Logger({ correlationIdSearchFn: searchFn }); - it('should handle undefined correlation ID gracefully', async () => { - // Prepare - const searchFn = vi.fn().mockReturnValue(undefined); - const logger = new Logger({ correlationIdSearchFn: searchFn }); - - const handler = middy(async () => { - logger.info('No correlation ID available'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'non.existent.path', - }) - ); + const handler = middy(async () => { + logger.info('No correlation ID available'); + }).use( + injectLambdaContext(logger, { + correlationIdPath: 'non.existent.path', + }) + ); + const testEvent = { + headers: { + 'x-correlation-id': '12345-test-id', + }, + }; - // Act - await handler(testEvent, context); + // Act + await handler(testEvent, context); - // Assess - expect(searchFn).toHaveBeenCalledWith('non.existent.path', testEvent); - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.not.objectContaining({ - correlation_id: expect.anything(), - }) - ); - }); + // Assess + expect(searchFn).toHaveBeenCalledWith('non.existent.path', testEvent); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.not.objectContaining({ + correlation_id: expect.anything(), + }) + ); }); }); From b67d631ae3779760ed3f6c83fda0fd174f03d05b Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 12:49:22 +0100 Subject: [PATCH 15/17] chore(docs): remove return statement form the docs --- packages/logger/src/correlationId.ts | 1 - 1 file changed, 1 deletion(-) diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts index 20bd7a363f..1e9ab271ce 100644 --- a/packages/logger/src/correlationId.ts +++ b/packages/logger/src/correlationId.ts @@ -8,7 +8,6 @@ import { PowertoolsFunctions } from '@aws-lambda-powertools/jmespath/functions'; * to extract the correlation ID from the event data. * @param expression - The JMESPath expression to use for searching the correlation ID. * @param data - The event data to search in. - * @returns - The correlation ID extracted from the event data. */ const search = (expression: string, data: unknown) => { return JMESPathSearch(expression, data as JSONObject, { From b3918a266c2c76064762116fcdee690fefed4aa9 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 15:04:56 +0100 Subject: [PATCH 16/17] chore: another batch of review --- docs/core/logger.md | 20 ++++++------ .../snippets/logger/correlationIdManual.ts | 11 +++---- .../snippets/logger/correlationIdMiddy.ts | 21 ++++++------ .../{ => samples}/correlationIdOutput.json | 0 .../{ => samples}/correlationIdPayload.json | 0 packages/logger/src/Logger.ts | 5 ++- .../tests/unit/injectLambdaContext.test.ts | 32 ------------------- 7 files changed, 24 insertions(+), 65 deletions(-) rename examples/snippets/logger/{ => samples}/correlationIdOutput.json (100%) rename examples/snippets/logger/{ => samples}/correlationIdPayload.json (100%) diff --git a/docs/core/logger.md b/docs/core/logger.md index 7218ba38e7..2712044e9d 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -209,7 +209,7 @@ Use `POWERTOOLS_LOGGER_LOG_EVENT` environment variable to enable or disable (`tr ### Setting a Correlation ID -To gest started, install `@aws-lambda-powertools/jmespath` package and configure the search function for the correlationId: +To get started, install the `@aws-lambda-powertools/jmespath` package, and pass the search function using the `correlationIdSearchFn` constructor parameter: === "Setup the Logger to use JMESPath search" @@ -224,39 +224,37 @@ You can set a correlation ID using `correlationIdPath` parameter by passing a JM === "Setting correlation ID manually" - ```typescript + ```typescript hl_lines="10" --8<-- "examples/snippets/logger/correlationIdManual.ts" ``` -=== "Middy.js Middleware" + 1. Alternatively, if the payload is more complex you can use a JMESPath expression as second parameter when prividing a search function in the constructor. - ```typescript + ```typescript hl_lines="19" --8<-- "examples/snippets/logger/correlationIdMiddy.ts" ``` -=== "Decorator" - - ```typescript + ```typescript hl_lines="11" --8<-- "examples/snippets/logger/correlationIdDecorator.ts" ``` === "payload.json" ```typescript - --8<-- "examples/snippets/logger/correlationIdPayload.json" + --8<-- "examples/snippets/logger/samples/correlationIdPayload.json" ``` === "log-output.json" ```json hl_lines="6" - --8<-- "examples/snippets/logger/correlationIdOutput.json" + --8<-- "examples/snippets/logger/samples/correlationIdOutput.json" ``` To ease routine tasks like extracting correlation ID from popular event sources, we provide built-in JMESPath expressions. === "Decorator" - ```typescript + ```typescript hl_lines="4 14" --8<-- "examples/snippets/logger/correlationIdPaths.ts" ``` @@ -270,7 +268,7 @@ To ease routine tasks like extracting correlation ID from popular event sources, | **APPSYNC_AUTHORIZER** | `'requestContext.requestId'` | AppSync resolver request ID | | **APPSYNC_RESOLVER** | `'request.headers."x-amzn-trace-id"'` | AppSync X-Ray Trace ID | | **APPLICATION_LOAD_BALANCER** | `'headers."x-amzn-trace-id"'` | ALB X-Ray Trace ID | -| **EVENT_BRIDGE** | `"id"` | EventBridge Event ID | +| **EVENT_BRIDGE** | `'id'` | EventBridge Event ID | | **LAMBDA_FUNCTION_URL** | `'requestContext.requestId'` | Lambda Function URL request ID | | **S3_OBJECT_LAMBDA** | `'xAmzRequestId'` | S3 Object trigger request ID | | **VPC_LATTICE** | `'headers."x-amzn-trace-id'` | VPC Lattice X-Ray Trace ID | diff --git a/examples/snippets/logger/correlationIdManual.ts b/examples/snippets/logger/correlationIdManual.ts index 527e700c25..1037bdd86f 100644 --- a/examples/snippets/logger/correlationIdManual.ts +++ b/examples/snippets/logger/correlationIdManual.ts @@ -1,13 +1,10 @@ import { Logger } from '@aws-lambda-powertools/logger'; -import type { APIGatewayProxyEvent, Context } from 'aws-lambda'; +import type { APIGatewayProxyEvent } from 'aws-lambda'; const logger = new Logger(); -export const handler = async ( - event: APIGatewayProxyEvent, - context: Context -): Promise => { - logger.setCorrelationId(event.requestContext.requestId); +export const handler = async (event: APIGatewayProxyEvent) => { + logger.setCorrelationId(event.requestContext.requestId); // (1)! - logger.info('This is an INFO log with some context'); + logger.info('log with correlation_id'); }; diff --git a/examples/snippets/logger/correlationIdMiddy.ts b/examples/snippets/logger/correlationIdMiddy.ts index 9258177a43..c0a4ff10d6 100644 --- a/examples/snippets/logger/correlationIdMiddy.ts +++ b/examples/snippets/logger/correlationIdMiddy.ts @@ -7,15 +7,12 @@ const logger = new Logger({ correlationIdSearchFn: search, }); -const lambdaHandler = async ( - _event: unknown, - _context: unknown -): Promise => { - logger.info('This is an INFO log with some context'); -}; - -export const handler = middy(lambdaHandler).use( - injectLambdaContext(logger, { - correlationIdPath: 'headers.my_request_id_header', - }) -); +export const handler = middy() + .use( + injectLambdaContext(logger, { + correlationIdPath: 'headers.my_request_id_header', + }) + ) + .handler(async () => { + logger.info('log with correlation_id'); + }); diff --git a/examples/snippets/logger/correlationIdOutput.json b/examples/snippets/logger/samples/correlationIdOutput.json similarity index 100% rename from examples/snippets/logger/correlationIdOutput.json rename to examples/snippets/logger/samples/correlationIdOutput.json diff --git a/examples/snippets/logger/correlationIdPayload.json b/examples/snippets/logger/samples/correlationIdPayload.json similarity index 100% rename from examples/snippets/logger/correlationIdPayload.json rename to examples/snippets/logger/samples/correlationIdPayload.json diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 15ee5d13c1..be5ae0dba8 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -1469,10 +1469,10 @@ class Logger extends Utility implements LoggerInterface { * * const logger = new Logger({ correlationIdSearchFn: search }); * logger.setCorrelationId(event, 'requestContext.requestId'); // sets the correlation ID from the event using JMSPath expression - * + * ``` * * @param value - The value to set as the correlation ID or the event to search for the correlation ID - * @param correlationIdPath - The path to search for the correlation ID in the event, if not set value is used directly + * @param correlationIdPath - Optional JMESPath expression to extract the correlation ID for the payload */ public setCorrelationId(value: unknown, correlationIdPath?: string): void { if (typeof correlationIdPath === 'string') { @@ -1496,7 +1496,6 @@ class Logger extends Utility implements LoggerInterface { /** * Get the correlation ID from the log attributes. - * @returns The correlation ID from the log attributes */ public getCorrelationId(): unknown { return this.temporaryLogAttributes.correlation_id; diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index cdd8079e98..949969e967 100644 --- a/packages/logger/tests/unit/injectLambdaContext.test.ts +++ b/packages/logger/tests/unit/injectLambdaContext.test.ts @@ -413,36 +413,4 @@ describe('Inject Lambda Context', () => { }) ); }); - - it('handles undefined correlation ID gracefully', async () => { - // Prepare - const searchFn = vi.fn().mockReturnValue(undefined); - const logger = new Logger({ correlationIdSearchFn: searchFn }); - - const handler = middy(async () => { - logger.info('No correlation ID available'); - }).use( - injectLambdaContext(logger, { - correlationIdPath: 'non.existent.path', - }) - ); - const testEvent = { - headers: { - 'x-correlation-id': '12345-test-id', - }, - }; - - // Act - await handler(testEvent, context); - - // Assess - expect(searchFn).toHaveBeenCalledWith('non.existent.path', testEvent); - expect(console.info).toHaveBeenCalledTimes(1); - expect(console.info).toHaveLoggedNth( - 1, - expect.not.objectContaining({ - correlation_id: expect.anything(), - }) - ); - }); }); From 9fe3bdec95dfb5d0adf8b4523db2da37c5d5a064 Mon Sep 17 00:00:00 2001 From: Alexander Schueren Date: Fri, 14 Mar 2025 15:15:54 +0100 Subject: [PATCH 17/17] chore: final touch of a sprinkle --- docs/core/logger.md | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index 2712044e9d..23b5d1ea9b 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -213,7 +213,7 @@ To get started, install the `@aws-lambda-powertools/jmespath` package, and pass === "Setup the Logger to use JMESPath search" - ```typescript + ```typescript hl_lines="5" --8<-- "examples/snippets/logger/correlationIdLogger.ts" ``` @@ -224,16 +224,20 @@ You can set a correlation ID using `correlationIdPath` parameter by passing a JM === "Setting correlation ID manually" - ```typescript hl_lines="10" + ```typescript hl_lines="7" --8<-- "examples/snippets/logger/correlationIdManual.ts" ``` 1. Alternatively, if the payload is more complex you can use a JMESPath expression as second parameter when prividing a search function in the constructor. - ```typescript hl_lines="19" +=== "Middy.js" + + ```typescript hl_lines="13" --8<-- "examples/snippets/logger/correlationIdMiddy.ts" ``` +=== "Decorator" + ```typescript hl_lines="11" --8<-- "examples/snippets/logger/correlationIdDecorator.ts" ```