diff --git a/docs/core/logger.md b/docs/core/logger.md index 7913ee3503..23b5d1ea9b 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -207,6 +207,76 @@ 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 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" + + ```typescript hl_lines="5" + --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 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. + +=== "Middy.js" + + ```typescript hl_lines="13" + --8<-- "examples/snippets/logger/correlationIdMiddy.ts" + ``` + +=== "Decorator" + + ```typescript hl_lines="11" + --8<-- "examples/snippets/logger/correlationIdDecorator.ts" + ``` + +=== "payload.json" + + ```typescript + --8<-- "examples/snippets/logger/samples/correlationIdPayload.json" + ``` + +=== "log-output.json" + + ```json hl_lines="6" + --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 hl_lines="4 14" + --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_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 | +| **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..f4b93fb7f4 --- /dev/null +++ b/examples/snippets/logger/correlationIdDecorator.ts @@ -0,0 +1,19 @@ +import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; +import { Logger } from '@aws-lambda-powertools/logger'; +import { search } from '@aws-lambda-powertools/logger/correlationId'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +class Lambda implements LambdaInterface { + @logger.injectLambdaContext({ + correlationIdPath: 'headers.my_request_id_header', + }) + public async handler(_event: unknown, _context: unknown): Promise<void> { + 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..3c003fb0a5 --- /dev/null +++ b/examples/snippets/logger/correlationIdLogger.ts @@ -0,0 +1,6 @@ +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 new file mode 100644 index 0000000000..1037bdd86f --- /dev/null +++ b/examples/snippets/logger/correlationIdManual.ts @@ -0,0 +1,10 @@ +import { Logger } from '@aws-lambda-powertools/logger'; +import type { APIGatewayProxyEvent } from 'aws-lambda'; + +const logger = new Logger(); + +export const handler = async (event: APIGatewayProxyEvent) => { + logger.setCorrelationId(event.requestContext.requestId); // (1)! + + logger.info('log with correlation_id'); +}; diff --git a/examples/snippets/logger/correlationIdMiddy.ts b/examples/snippets/logger/correlationIdMiddy.ts new file mode 100644 index 0000000000..c0a4ff10d6 --- /dev/null +++ b/examples/snippets/logger/correlationIdMiddy.ts @@ -0,0 +1,18 @@ +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'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +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/correlationIdPaths.ts b/examples/snippets/logger/correlationIdPaths.ts new file mode 100644 index 0000000000..b6cb3f500e --- /dev/null +++ b/examples/snippets/logger/correlationIdPaths.ts @@ -0,0 +1,22 @@ +import type { LambdaInterface } from '@aws-lambda-powertools/commons/types'; +import { Logger } from '@aws-lambda-powertools/logger'; +import { + correlationPaths, + search, +} from '@aws-lambda-powertools/logger/correlationId'; + +const logger = new Logger({ + correlationIdSearchFn: search, +}); + +class Lambda implements LambdaInterface { + @logger.injectLambdaContext({ + correlationIdPath: correlationPaths.API_GATEWAY_REST, + }) + public async handler(_event: unknown, _context: unknown): Promise<void> { + 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/samples/correlationIdOutput.json b/examples/snippets/logger/samples/correlationIdOutput.json new file mode 100644 index 0000000000..b71e1984dc --- /dev/null +++ b/examples/snippets/logger/samples/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/samples/correlationIdPayload.json b/examples/snippets/logger/samples/correlationIdPayload.json new file mode 100644 index 0000000000..ce2e8d8014 --- /dev/null +++ b/examples/snippets/logger/samples/correlationIdPayload.json @@ -0,0 +1,5 @@ +{ + "headers": { + "my_request_id_header": "correlation_id_value" + } +} diff --git a/packages/logger/package.json b/packages/logger/package.json index 544314ce05..acf8b56457 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": { @@ -68,16 +72,18 @@ "@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": [ - "lib" - ], + "files": ["lib"], "repository": { "type": "git", "url": "git+https://github.com/aws-powertools/powertools-lambda-typescript.git" diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index babfc4f77c..be5ae0dba8 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -215,6 +215,11 @@ class Logger extends Utility implements LoggerInterface { */ #buffer?: CircularMap<string>; + /** + * Search function for the correlation ID. + */ + #correlationIdSearchFn?: (expression: string, data: unknown) => unknown; + /** * The debug sampling rate configuration. */ @@ -326,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, @@ -480,6 +486,9 @@ class Logger extends Utility implements LoggerInterface { loggerRef.refreshSampleRateCalculation(); loggerRef.addContext(context); loggerRef.logEventIfEnabled(event, options?.logEvent); + if (options?.correlationIdPath) { + loggerRef.setCorrelationId(event, options?.correlationIdPath); + } try { return await originalMethod.apply(this, [event, context, callback]); @@ -1261,6 +1270,7 @@ class Logger extends Utility implements LoggerInterface { jsonReplacerFn, logRecordOrder, logBufferOptions, + correlationIdSearchFn, } = options; if (persistentLogAttributes && persistentKeys) { @@ -1287,6 +1297,7 @@ class Logger extends Utility implements LoggerInterface { this.setLogIndentation(); this.#jsonReplacerFn = jsonReplacerFn; this.#setLogBuffering(logBufferOptions); + this.#correlationIdSearchFn = correlationIdSearchFn; return this; } @@ -1439,6 +1450,56 @@ class Logger extends Utility implements LoggerInterface { logLevel <= this.#bufferConfig.bufferAtVerbosity ); } + + /** + * 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 - Optional JMESPath expression to extract the correlation ID for the payload + */ + 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, + value + ); + if (correlationId) this.appendKeys({ correlation_id: correlationId }); + return; + } + + // If no correlationIdPath is provided, set the correlation ID directly + this.appendKeys({ correlation_id: value }); + } + + /** + * Get the correlation ID from the log attributes. + */ + public getCorrelationId(): unknown { + return this.temporaryLogAttributes.correlation_id; + } } export { Logger }; diff --git a/packages/logger/src/correlationId.ts b/packages/logger/src/correlationId.ts new file mode 100644 index 0000000000..1e9ab271ce --- /dev/null +++ b/packages/logger/src/correlationId.ts @@ -0,0 +1,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'; + +/** + * 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. + */ +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/index.ts b/packages/logger/src/index.ts index ae100eb930..f736cbff35 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,4 +1,4 @@ -export { Logger } from './Logger.js'; +export { LogLevel, LogLevelThreshold } from './constants.js'; export { LogFormatter } from './formatter/LogFormatter.js'; export { LogItem } from './formatter/LogItem.js'; -export { LogLevel, LogLevelThreshold } from './constants.js'; +export { Logger } from './Logger.js'; diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index f85b1af9f8..eeaef4fd49 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -95,6 +95,10 @@ const injectLambdaContext = ( request.context, options ); + + if (options?.correlationIdPath) { + logger.setCorrelationId(request.event, options.correlationIdPath); + } } }; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 01b7fbad20..e127f9441d 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[]; @@ -252,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; @@ -260,14 +274,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..30a0e6a1d7 100644 --- a/packages/logger/src/types/index.ts +++ b/packages/logger/src/types/index.ts @@ -1,12 +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'; diff --git a/packages/logger/tests/unit/injectLambdaContext.test.ts b/packages/logger/tests/unit/injectLambdaContext.test.ts index 9518e5b6af..949969e967 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 = { @@ -239,4 +240,177 @@ describe('Inject Lambda Context', () => { ); } ); + + 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<void> { + 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', + }, + }; + + // 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'); + }); + + 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', + }) + ); + + 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('does 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({ foo: 'bar' }, context); + + // Assess + expect(logger.getCorrelationId()).toBeUndefined(); + expect(console.info).toHaveBeenCalledTimes(1); + expect(console.info).toHaveLoggedNth( + 1, + expect.not.objectContaining({ + correlation_id: expect.anything(), + }) + ); + }); + + it('propagates search function to child loggers', () => { + // Prepare + const mockSearch = vi.fn().mockReturnValue('found-id'); + const logger = new Logger({ correlationIdSearchFn: mockSearch }); + + // Act + const childLogger = logger.createChild(); + childLogger.setCorrelationId({ some: 'event' }, 'some.path'); + + // Assess + expect(mockSearch).toHaveBeenCalledWith('some.path', { some: 'event' }); + expect(childLogger.getCorrelationId()).toBe('found-id'); + }); + + it('allows 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('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', + }, + }; + + // 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', + }) + ); + }); });