From 690403bfc0720e27829fe685a85370b36899a488 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 28 Feb 2025 11:32:55 +0100 Subject: [PATCH 1/4] feat(logger): flush buffer on uncaught error decorator --- packages/logger/src/Logger.ts | 81 ++-- packages/logger/src/constants.ts | 14 +- packages/logger/src/types/Logger.ts | 8 +- packages/logger/tests/unit/logBuffer.test.ts | 405 ++++++++++--------- 4 files changed, 285 insertions(+), 223 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index bb93df7d32..79dcfd7792 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -9,7 +9,12 @@ import type { import type { Context, Handler } from 'aws-lambda'; import merge from 'lodash.merge'; import { EnvironmentVariablesService } from './config/EnvironmentVariablesService.js'; -import { LogJsonIndent, LogLevelThreshold, ReservedKeys } from './constants.js'; +import { + LogJsonIndent, + LogLevelThreshold, + ReservedKeys, + UncaughtErrorLogMessage, +} from './constants.js'; import type { LogFormatter } from './formatter/LogFormatter.js'; import type { LogItem } from './formatter/LogItem.js'; import { PowertoolsLogFormatter } from './formatter/PowertoolsLogFormatter.js'; @@ -39,6 +44,7 @@ import type { * * Capture key fields from AWS Lambda context, cold start, and structure log output as JSON * * Append additional keys to one or all log items * * Switch log level to `DEBUG` based on a sample rate value for a percentage of invocations + * * Ability to buffer logs in memory and flush them when there's an error * * After initializing the Logger class, you can use the methods to log messages at different levels. * @@ -54,7 +60,7 @@ import type { * }; * ``` * - * To enrich the log items with information from the Lambda context, you can use the {@link Logger.addContext | addContext()} method. + * To enrich the log items with information from the Lambda context, you can use the {@link Logger.addContext | `addContext()`} method. * * @example * ```typescript @@ -69,7 +75,7 @@ import type { * }; * ``` * - * You can also add additional attributes to all log items using the {@link Logger.appendKeys | appendKeys()} method. + * You can also add additional attributes to all log items using the {@link Logger.appendKeys | `appendKeys()`} method. * * @example * ```typescript @@ -82,10 +88,10 @@ import type { * }; *``` * - * If you write your functions as classes and use TypeScript, you can use the {@link Logger.injectLambdaContext} class method decorator + * If you write your functions as classes and use TypeScript, you can use the {@link Logger.injectLambdaContext | `injectLambdaContext()`} class method decorator * to automatically add context to your logs and clear the state after the invocation. * - * If instead you use Middy.js middlewares, you use the {@link "middleware/middy".injectLambdaContext | injectLambdaContext()} middleware. + * If instead you use Middy.js middlewares, you use the {@link "middleware/middy".injectLambdaContext | `injectLambdaContext()`} middleware. * * @see https://docs.powertools.aws.dev/lambda/typescript/latest/core/logger/ */ @@ -97,7 +103,7 @@ class Logger extends Utility implements LoggerInterface { * full control over the output of the logs. In testing environments, we use the * default console instance. * - * This property is initialized in the constructor in setOptions(). + * This property is initialized in the constructor in `setOptions()`. */ private console!: Console; /** @@ -191,7 +197,7 @@ class Logger extends Utility implements LoggerInterface { #maxBufferBytesSize = 20480; /** - * Contains buffered logs, grouped by _X_AMZN_TRACE_ID, each group with a max size of `maxBufferBytesSize` + * Contains buffered logs, grouped by `_X_AMZN_TRACE_ID`, each group with a max size of `maxBufferBytesSize` */ #buffer?: CircularMap; @@ -420,16 +426,23 @@ class Logger extends Utility implements LoggerInterface { callback ) { loggerRef.refreshSampleRateCalculation(); - Logger.injectLambdaContextBefore(loggerRef, event, context, options); + loggerRef.addContext(context); + loggerRef.logEventIfEnabled(event, options?.logEvent); - let result: unknown; try { - result = await originalMethod.apply(this, [event, context, callback]); + return await originalMethod.apply(this, [event, context, callback]); + } catch (error) { + if (options?.flushBufferOnUncaughtError) { + loggerRef.flushBuffer(); + loggerRef.error({ + message: UncaughtErrorLogMessage, + error, + }); + } + throw error; } finally { if (options?.clearState || options?.resetKeys) loggerRef.resetKeys(); } - - return result; }; }; } @@ -450,7 +463,7 @@ class Logger extends Utility implements LoggerInterface { /** * @deprecated - This method is deprecated and will be removed in the next major version. */ - public static injectLambdaContextBefore( + /* v8 ignore start */ public static injectLambdaContextBefore( logger: Logger, event: unknown, context: Context, @@ -463,7 +476,7 @@ class Logger extends Utility implements LoggerInterface { shouldLogEvent = options.logEvent; } logger.logEventIfEnabled(event, shouldLogEvent); - } + } /* v8 ignore stop */ /** * Log the AWS Lambda event payload for the current invocation if the environment variable `POWERTOOLS_LOGGER_LOG_EVENT` is set to `true`. @@ -1239,6 +1252,11 @@ class Logger extends Utility implements LoggerInterface { persistentKeys && this.appendPersistentKeys(persistentKeys); } + /** + * Configure the buffer settings for the Logger instance. + * + * @param options - Options to configure the Logger instance + */ #setLogBuffering( options: NonNullable ) { @@ -1269,10 +1287,11 @@ class Logger extends Utility implements LoggerInterface { } /** - * Add a log to the buffer - * @param xrayTraceId - _X_AMZN_TRACE_ID of the request + * Add a log to the buffer. + * + * @param xrayTraceId - `_X_AMZN_TRACE_ID` of the request * @param log - Log to be buffered - * @param logLevel - level of log to be buffered + * @param logLevel - The level of log to be buffered */ protected bufferLogItem( xrayTraceId: string, @@ -1280,19 +1299,22 @@ class Logger extends Utility implements LoggerInterface { logLevel: number ): void { log.prepareForPrint(); - - const stringified = JSON.stringify( - log.getAttributes(), - this.getJsonReplacer(), - this.logIndentation + this.#buffer?.setItem( + xrayTraceId, + JSON.stringify( + log.getAttributes(), + this.getJsonReplacer(), + this.logIndentation + ), + logLevel ); - - this.#buffer?.setItem(xrayTraceId, stringified, logLevel); } /** - * Flushes all items of the respective _X_AMZN_TRACE_ID within - * the buffer. + * Flush all logs in the request buffer. + * + * This is called automatically when you use the {@link injectLambdaContext | `@logger.injectLambdaContext()`} decorator and + * your function throws an error. */ public flushBuffer(): void { const traceId = this.envVarsService.getXrayTraceId(); @@ -1328,9 +1350,10 @@ class Logger extends Utility implements LoggerInterface { this.#buffer?.delete(traceId); } /** - * Tests if the log meets the criteria to be buffered - * @param traceId - _X_AMZN_TRACE_ID of the request - * @param logLevel - The level of the log being considered + * Test if the log meets the criteria to be buffered. + * + * @param traceId - `_X_AMZN_TRACE_ID` of the request + * @param logLevel - The level of the log being considered */ protected shouldBufferLog( traceId: string | undefined, diff --git a/packages/logger/src/constants.ts b/packages/logger/src/constants.ts index a95ed293c7..38b3adef37 100644 --- a/packages/logger/src/constants.ts +++ b/packages/logger/src/constants.ts @@ -50,4 +50,16 @@ const ReservedKeys = [ 'timestamp', ]; -export { LogJsonIndent, LogLevel, LogLevelThreshold, ReservedKeys }; +/** + * Message logged when an uncaught error occurs in a Lambda function. + */ +const UncaughtErrorLogMessage = + 'Uncaught error detected, flushing log buffer before exit'; + +export { + LogJsonIndent, + LogLevel, + LogLevelThreshold, + ReservedKeys, + UncaughtErrorLogMessage, +}; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 819f35d898..899d6078da 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -48,6 +48,12 @@ type InjectLambdaContextOptions = { * If `true`, the logger will reset the keys added via {@link LoggerInterface.appendKeys()} */ resetKeys?: boolean; + /** + * Whether to flush the log buffer when an uncaught error is logged. + * + * @default `false` + */ + flushBufferOnUncaughtError?: boolean; }; /** @@ -197,7 +203,7 @@ type LogBufferOption = { /** * The threshold to buffer logs. Logs with a level below * this threshold will be buffered - * @default `'DEBUG'` + * @default `DEBUG` */ bufferAtVerbosity?: Omit< LogLevel, diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index f7e4558c73..fc418be6cb 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -1,231 +1,252 @@ -import { beforeEach, describe, expect, it, vi } from 'vitest'; +import context from '@aws-lambda-powertools/testing-utils/context'; +import type { Context } from 'aws-lambda'; +import { type Mock, beforeEach, describe, expect, it, vi } from 'vitest'; import { Logger } from '../../src/Logger.js'; import { LogLevel } from '../../src/constants.js'; +import { UncaughtErrorLogMessage } from '../../src/constants.js'; +import type { ConstructorOptions } from '../../src/types/Logger.js'; + +describe('Buffer logs', () => { + const ENVIRONMENT_VARIABLES = process.env; + + beforeEach(() => { + process.env = { + ...ENVIRONMENT_VARIABLES, + POWERTOOLS_DEV: 'true', + }; + vi.clearAllMocks(); + }); -class TestLogger extends Logger { - public overrideBufferLogItem(): void { - this.bufferLogItem = vi.fn().mockImplementation(() => { - throw new Error('bufferLogItem error'); - }); - } -} -describe('Log Buffer', () => { - describe('Configuration', () => { - const ENVIRONMENT_VARIABLES = process.env; - - beforeEach(() => { - process.env = { - ...ENVIRONMENT_VARIABLES, - POWERTOOLS_LOGGER_LOG_EVENT: 'true', - POWERTOOLS_DEV: 'true', - }; - vi.clearAllMocks(); + it('does not buffer logs when disabled', () => { + // Prepare + const logger = new Logger({ + logLevel: LogLevel.ERROR, + logBufferOptions: { enabled: false }, }); - it('does not buffer logs when disabled', () => { - // Prepare - const logger = new TestLogger({ - logLevel: LogLevel.ERROR, - logBufferOptions: { enabled: false }, - }); - - // Act - logger.debug('This is a log message'); - logger.flushBuffer(); - // Assess - expect(console.debug).toBeCalledTimes(0); - }); + // Act + logger.debug('This is a log message'); + logger.flushBuffer(); + // Assess + expect(console.debug).toBeCalledTimes(0); + }); - it('does not flush on error logs when flushOnErrorLog is disabled ', () => { - // Prepare - const logger = new TestLogger({ - logLevel: LogLevel.ERROR, - logBufferOptions: { enabled: true, flushOnErrorLog: false }, - }); - - // Act - logger.debug('This is a log message'); - logger.error('This is an error message'); - // Assess - expect(console.debug).toBeCalledTimes(0); - expect(console.error).toBeCalledTimes(1); + it('does not flush on error logs when flushOnErrorLog is disabled ', () => { + // Prepare + const logger = new Logger({ + logLevel: LogLevel.ERROR, + logBufferOptions: { enabled: true, flushOnErrorLog: false }, }); - it('buffers logs when the config object is provided, but not specifically enabled', () => { - // Prepare - const logger = new TestLogger({ - logLevel: LogLevel.ERROR, - logBufferOptions: { maxBytes: 100 }, - }); - - // Act - logger.debug('This is a log message'); - logger.flushBuffer(); - // Assess - expect(console.debug).toBeCalledTimes(1); - }); + // Act + logger.debug('This is a log message'); + logger.error('This is an error message'); + // Assess + expect(console.debug).toBeCalledTimes(0); + expect(console.error).toBeCalledTimes(1); + }); - it('sets a max buffer sized when specified', () => { - // Prepare - const logger = new TestLogger({ - logBufferOptions: { - maxBytes: 250, - bufferAtVerbosity: LogLevel.DEBUG, - enabled: true, - }, - }); - - // Act - logger.debug('this is a debug'); - logger.debug('this is a debug'); - logger.flushBuffer(); - - // Assess - expect(console.debug).toBeCalledTimes(1); - expect(console.warn).toHaveLogged( - expect.objectContaining({ - level: 'WARN', - message: - 'Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer', - }) - ); + it('buffers logs when the config object is provided, but not specifically enabled', () => { + // Prepare + const logger = new Logger({ + logLevel: LogLevel.ERROR, + logBufferOptions: { maxBytes: 100 }, }); - }); - describe('Functionality', () => { - const ENVIRONMENT_VARIABLES = process.env; + // Act + logger.debug('This is a log message'); + logger.flushBuffer(); + // Assess + expect(console.debug).toBeCalledTimes(1); + }); - beforeEach(() => { - process.env = { - ...ENVIRONMENT_VARIABLES, - POWERTOOLS_LOGGER_LOG_EVENT: 'true', - POWERTOOLS_DEV: 'true', - }; - vi.clearAllMocks(); - }); - it('outputs a warning when there is an error buffering the log', () => { - // Prepare - process.env.POWERTOOLS_DEV = 'true'; - const logger = new TestLogger({ logBufferOptions: { enabled: true } }); - logger.overrideBufferLogItem(); - - // Act - logger.debug('This is a debug'); - - // Assess - expect(console.debug).toBeCalledTimes(1); - expect(console.warn).toBeCalledTimes(1); + it('sets a max buffer sized when specified', () => { + // Prepare + const logger = new Logger({ + logBufferOptions: { + maxBytes: 250, + bufferAtVerbosity: LogLevel.DEBUG, + enabled: true, + }, }); - it('outputs buffered logs', () => { - // Prepare - const logger = new TestLogger({ - logLevel: 'SILENT', - logBufferOptions: { - enabled: true, - bufferAtVerbosity: LogLevel.CRITICAL, - }, - }); + // Act + logger.debug('this is a debug'); + logger.debug('this is a debug'); + logger.flushBuffer(); + + // Assess + expect(console.debug).toBeCalledTimes(1); + expect(console.warn).toHaveLogged( + expect.objectContaining({ + level: 'WARN', + message: + 'Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer', + }) + ); + }); - // Act - logger.debug('This is a debug'); - logger.warn('This is a warning'); - logger.critical('this is a critical'); + it('outputs a warning when there is an error buffering the log', () => { + // Prepare + class MockLogger extends Logger { + constructor(options: ConstructorOptions) { + super(options); + // We want to simulate an error in the bufferLogItem method, which is protected, so we override it + this.bufferLogItem = vi.fn().mockImplementation(() => { + throw new Error('bufferLogItem error'); + }); + } + } + const logger = new MockLogger({ logBufferOptions: { enabled: true } }); - // Assess - expect(console.warn).toHaveBeenCalledTimes(0); - expect(console.error).toHaveBeenCalledTimes(0); + // Act + logger.debug('This is a debug'); - // Act - logger.flushBuffer(); + // Assess + expect(console.debug).toBeCalledTimes(1); + expect(console.warn).toBeCalledTimes(1); + }); - // Assess - expect(console.warn).toHaveBeenCalledTimes(1); - expect(console.error).toHaveBeenCalledTimes(1); + it('outputs buffered logs', () => { + // Prepare + const logger = new Logger({ + logLevel: 'SILENT', + logBufferOptions: { + enabled: true, + bufferAtVerbosity: LogLevel.CRITICAL, + }, }); - it('handles an empty buffer', () => { - // Prepare - const logger = new TestLogger({ logBufferOptions: { enabled: true } }); + // Act + logger.debug('This is a debug'); + logger.warn('This is a warning'); + logger.critical('this is a critical'); - // Act - logger.flushBuffer(); - }); + // Assess + expect(console.warn).toHaveBeenCalledTimes(0); + expect(console.error).toHaveBeenCalledTimes(0); - it('does not output buffered logs when trace id is not set', () => { - // Prepare - process.env._X_AMZN_TRACE_ID = undefined; - const logger = new TestLogger({ logBufferOptions: { enabled: true } }); + // Act + logger.flushBuffer(); - // Act - logger.debug('This is a debug'); - logger.warn('this is a warning'); + // Assess + expect(console.warn).toHaveBeenCalledTimes(1); + expect(console.error).toHaveBeenCalledTimes(1); + }); - // Assess - expect(console.debug).toHaveBeenCalledTimes(0); - expect(console.warn).toHaveBeenCalledTimes(1); + it('handles an empty buffer', () => { + // Prepare + const logger = new Logger({ logBufferOptions: { enabled: true } }); - // Act - logger.flushBuffer(); + // Act & Assess + expect(() => logger.flushBuffer()).not.toThrow(); + }); - // Assess - expect(console.debug).toHaveBeenCalledTimes(0); - expect(console.warn).toHaveBeenCalledTimes(1); - }); + it('does not output buffered logs when trace id is not set', () => { + // Prepare + process.env._X_AMZN_TRACE_ID = undefined; + const logger = new Logger({ logBufferOptions: { enabled: true } }); - it('outputs a warning when buffered logs have been evicted', () => { - // Prepare - const logger = new TestLogger({ - logLevel: LogLevel.ERROR, - logBufferOptions: { - enabled: true, - bufferAtVerbosity: LogLevel.INFO, - maxBytes: 1024, - }, - }); + // Act + logger.debug('This is a debug'); + logger.warn('this is a warning'); - // Act - const longMessage = 'blah'.repeat(10); + // Assess + expect(console.debug).toHaveBeenCalledTimes(0); + expect(console.warn).toHaveBeenCalledTimes(1); - let i = 0; - while (i < 4) { - logger.info( - `${i} This is a really long log message intended to exceed the buffer ${longMessage}` - ); - i++; - } + // Act + logger.flushBuffer(); - // Act - logger.flushBuffer(); + // Assess + expect(console.debug).toHaveBeenCalledTimes(0); + expect(console.warn).toHaveBeenCalledTimes(1); + }); - // Assess - expect(console.warn).toHaveLogged( - expect.objectContaining({ - level: LogLevel.WARN, - message: - 'Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer', - }) - ); + it('outputs a warning when buffered logs have been evicted', () => { + // Prepare + const logger = new Logger({ + logLevel: LogLevel.ERROR, + logBufferOptions: { + enabled: true, + bufferAtVerbosity: LogLevel.INFO, + maxBytes: 1024, + }, }); - it('it flushes the buffer when an error in logged', () => { - // Prepare - const logger = new TestLogger({ - logLevel: LogLevel.ERROR, - logBufferOptions: { enabled: true, bufferAtVerbosity: LogLevel.DEBUG }, - }); + // Act + const longMessage = 'blah'.repeat(10); - const spy = vi.spyOn(logger, 'flushBuffer'); + let i = 0; + while (i < 4) { + logger.info( + `${i} This is a really long log message intended to exceed the buffer ${longMessage}` + ); + i++; + } + logger.flushBuffer(); + + // Assess + expect(console.warn).toHaveLogged( + expect.objectContaining({ + level: LogLevel.WARN, + message: + 'Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer', + }) + ); + }); - // Act - logger.debug('This is a log message'); + it('it flushes the buffer when an error in logged', () => { + // Prepare + const logger = new Logger({ + logLevel: LogLevel.ERROR, + logBufferOptions: { enabled: true, bufferAtVerbosity: LogLevel.DEBUG }, + }); + const flushBufferSpy = vi.spyOn(logger, 'flushBuffer'); - logger.error('This is an error message'); + // Act + logger.debug('This is a log message'); + logger.error('This is an error message'); - // Assess - expect(spy).toBeCalledTimes(1); - expect(console.debug).toBeCalledTimes(1); - expect(console.error).toBeCalledTimes(1); - }); + // Assess + expect(flushBufferSpy).toBeCalledTimes(1); + expect(console.debug).toBeCalledTimes(1); + expect(console.error).toBeCalledTimes(1); + }); + + it('adds the context to the messages when the feature is enabled using the class method decorator', async () => { + // Prepare + const logger = new Logger({ logBufferOptions: { enabled: true } }); + class TestClass { + @logger.injectLambdaContext({ flushBufferOnUncaughtError: true }) + async handler(_event: unknown, _context: Context) { + logger.debug('This is a log message'); + logger.info('This is an info message'); + throw new Error('This is an error'); + } + } + const lambda = new TestClass(); + const handler = lambda.handler.bind(lambda); + + // Act & Assess + await expect(() => + handler( + { + foo: 'bar', + }, + context + ) + ).rejects.toThrow('This is an error'); + expect(console.debug).toBeCalledTimes(1); + expect(console.info).toBeCalledTimes(1); + expect(console.error).toHaveLogged( + expect.objectContaining({ + message: UncaughtErrorLogMessage, + }) + ); + // If debug is called after info, it means it was buffered and then flushed + expect(console.debug).toHaveBeenCalledAfter(console.info as Mock); + // If error is called after debug, it means the buffer was flushed before the error log + expect(console.debug).toHaveBeenCalledBefore(console.error as Mock); }); }); From 2a5e136a8cb45bdea47c0544253e1346c9a62d2e Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 28 Feb 2025 12:08:50 +0100 Subject: [PATCH 2/4] test: coverage --- packages/logger/src/Logger.ts | 2 ++ packages/logger/tests/unit/logBuffer.test.ts | 32 ++++++++++++++++++-- 2 files changed, 32 insertions(+), 2 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 79dcfd7792..5d73ff60d9 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -440,7 +440,9 @@ class Logger extends Utility implements LoggerInterface { }); } throw error; + /* v8 ignore start */ } finally { + /* v8 ignore stop */ if (options?.clearState || options?.resetKeys) loggerRef.resetKeys(); } }; diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index fc418be6cb..90375de9b5 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -214,7 +214,7 @@ describe('Buffer logs', () => { expect(console.error).toBeCalledTimes(1); }); - it('adds the context to the messages when the feature is enabled using the class method decorator', async () => { + it('flushes the buffer when an uncaught error is thrown', async () => { // Prepare const logger = new Logger({ logBufferOptions: { enabled: true } }); class TestClass { @@ -236,7 +236,7 @@ describe('Buffer logs', () => { }, context ) - ).rejects.toThrow('This is an error'); + ).rejects.toThrow(new Error('This is an error')); expect(console.debug).toBeCalledTimes(1); expect(console.info).toBeCalledTimes(1); expect(console.error).toHaveLogged( @@ -249,4 +249,32 @@ describe('Buffer logs', () => { // If error is called after debug, it means the buffer was flushed before the error log expect(console.debug).toHaveBeenCalledBefore(console.error as Mock); }); + + it('adds the context to the messages when the feature is enabled using the class method decorator', async () => { + // Prepare + const logger = new Logger({ logBufferOptions: { enabled: true } }); + class TestClass { + @logger.injectLambdaContext({}) + async handler(_event: unknown, _context: Context) { + logger.debug('This is a log message'); + logger.info('This is an info message'); + throw new Error('This is an error'); + } + } + const lambda = new TestClass(); + const handler = lambda.handler.bind(lambda); + + // Act & Assess + await expect(() => + handler( + { + foo: 'bar', + }, + context + ) + ).rejects.toThrow(new Error('This is an error')); + expect(console.debug).toBeCalledTimes(0); + expect(console.info).toBeCalledTimes(1); + expect(console.error).toBeCalledTimes(0); + }); }); From 4546fe3a1f16a85254c688370c01385841476162 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 28 Feb 2025 12:18:40 +0100 Subject: [PATCH 3/4] docs: add info about options in decorator description --- packages/logger/src/Logger.ts | 18 ++++++++++++++---- 1 file changed, 14 insertions(+), 4 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 5d73ff60d9..08843747fe 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -385,8 +385,8 @@ class Logger extends Utility implements LoggerInterface { * Class method decorator that adds the current Lambda function context as extra * information in all log items. * - * This decorator is useful when you want to add the Lambda context to all log items - * and it works only when decorating a class method that is a Lambda function handler. + * This decorator is useful when you want to enrich your logs with information + * from the function context, such as the function name, version, and request ID, and more. * * @example * ```typescript @@ -407,7 +407,18 @@ class Logger extends Utility implements LoggerInterface { * export const handler = handlerClass.handler.bind(handlerClass); * ``` * + * The decorator can also be used to log the Lambda invocation event; this can be configured both via + * the `logEvent` parameter and the `POWERTOOLS_LOGGER_LOG_EVENT` environment variable. When both + * are set, the `logEvent` parameter takes precedence. + * + * Additionally, the decorator can be used to reset the temporary keys added with the `appendKeys()` method + * after the invocation, or to flush the buffer when an uncaught error is thrown in the handler. + * * @see https://www.typescriptlang.org/docs/handbook/decorators.html#method-decorators + * + * @param options.logEvent - When `true` the logger will log the event. + * @param options.resetKeys - When `true` the logger will clear temporary keys added with {@link Logger.appendKeys() `appendKeys()`} method. + * @param options.flushBufferOnUncaughtError - When `true` the logger will flush the buffer when an uncaught error is thrown in the handler. */ public injectLambdaContext( options?: InjectLambdaContextOptions @@ -440,9 +451,8 @@ class Logger extends Utility implements LoggerInterface { }); } throw error; - /* v8 ignore start */ + /* v8 ignore next */ } finally { - /* v8 ignore stop */ if (options?.clearState || options?.resetKeys) loggerRef.resetKeys(); } }; From 8fa65a1717a35923e7da02f251f7c0acc6c10fbb Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 28 Feb 2025 12:29:36 +0100 Subject: [PATCH 4/4] test: remove redundant test --- packages/logger/tests/unit/logBuffer.test.ts | 31 +------------------- 1 file changed, 1 insertion(+), 30 deletions(-) diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index 90375de9b5..4ec8fb1061 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -2,8 +2,7 @@ import context from '@aws-lambda-powertools/testing-utils/context'; import type { Context } from 'aws-lambda'; import { type Mock, beforeEach, describe, expect, it, vi } from 'vitest'; import { Logger } from '../../src/Logger.js'; -import { LogLevel } from '../../src/constants.js'; -import { UncaughtErrorLogMessage } from '../../src/constants.js'; +import { LogLevel, UncaughtErrorLogMessage } from '../../src/constants.js'; import type { ConstructorOptions } from '../../src/types/Logger.js'; describe('Buffer logs', () => { @@ -249,32 +248,4 @@ describe('Buffer logs', () => { // If error is called after debug, it means the buffer was flushed before the error log expect(console.debug).toHaveBeenCalledBefore(console.error as Mock); }); - - it('adds the context to the messages when the feature is enabled using the class method decorator', async () => { - // Prepare - const logger = new Logger({ logBufferOptions: { enabled: true } }); - class TestClass { - @logger.injectLambdaContext({}) - async handler(_event: unknown, _context: Context) { - logger.debug('This is a log message'); - logger.info('This is an info message'); - throw new Error('This is an error'); - } - } - const lambda = new TestClass(); - const handler = lambda.handler.bind(lambda); - - // Act & Assess - await expect(() => - handler( - { - foo: 'bar', - }, - context - ) - ).rejects.toThrow(new Error('This is an error')); - expect(console.debug).toBeCalledTimes(0); - expect(console.info).toBeCalledTimes(1); - expect(console.error).toBeCalledTimes(0); - }); });