From b234e4d06d8d16501a161fbcd74a6581c2d8202b Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Mon, 3 Mar 2025 14:52:35 +0000
Subject: [PATCH 1/8] Add clearBuffer method
The clearBuffer method clears the logger buffer.
---
packages/logger/src/Logger.ts | 15 +++++++++++++++
1 file changed, 15 insertions(+)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index d83c26bc66..1c4e958120 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -1361,6 +1361,21 @@ class Logger extends Utility implements LoggerInterface {
this.#buffer?.delete(traceId);
}
+
+ /**
+ * Empties the buffer for the current request
+ *
+ */
+ public clearBuffer(): void {
+ const traceId = this.envVarsService.getXrayTraceId();
+
+ if (traceId === undefined) {
+ return;
+ }
+
+ this.#buffer?.delete(traceId);
+ }
+
/**
* Test if the log meets the criteria to be buffered.
*
From 808cc79505e333b7b842f3909565ecfa64368f7d Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Mon, 3 Mar 2025 14:53:22 +0000
Subject: [PATCH 2/8] Flush buffer on uncaught error in middy middleware
---
packages/logger/src/middleware/middy.ts | 30 +++++++++++-----
packages/logger/tests/unit/logBuffer.test.ts | 37 ++++++++++++++++++++
2 files changed, 59 insertions(+), 8 deletions(-)
diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts
index 804444c4b4..2af8559d54 100644
--- a/packages/logger/src/middleware/middy.ts
+++ b/packages/logger/src/middleware/middy.ts
@@ -4,6 +4,7 @@ import type {
MiddyLikeRequest,
} from '@aws-lambda-powertools/commons/types';
import { Logger } from '../Logger.js';
+import { UncaughtErrorLogMessage } from '../constants.js';
import type { InjectLambdaContextOptions } from '../types/Logger.js';
/**
@@ -76,13 +77,11 @@ const injectLambdaContext = (
const setCleanupFunction = (request: MiddyLikeRequest): void => {
request.internal = {
...request.internal,
- [LOGGER_KEY]: injectLambdaContextAfterOrOnError,
+ [LOGGER_KEY]: onAfter,
};
};
- const injectLambdaContextBefore = async (
- request: MiddyLikeRequest
- ): Promise<void> => {
+ const onBefore = async (request: MiddyLikeRequest): Promise<void> => {
for (const logger of loggers) {
if (isResetStateEnabled) {
setCleanupFunction(request);
@@ -99,18 +98,33 @@ const injectLambdaContext = (
}
};
- const injectLambdaContextAfterOrOnError = async (): Promise<void> => {
+ const onAfter = async (): Promise<void> => {
if (isResetStateEnabled) {
for (const logger of loggers) {
logger.resetKeys();
}
}
+
+ for (const logger of loggers) {
+ logger.clearBuffer();
+ }
+ };
+ const onError = async ({ error }): Promise<void> => {
+ if (options?.flushBufferOnUncaughtError) {
+ for (const logger of loggers) {
+ logger.flushBuffer();
+ logger.error({
+ message: UncaughtErrorLogMessage,
+ error,
+ });
+ }
+ }
};
return {
- before: injectLambdaContextBefore,
- after: injectLambdaContextAfterOrOnError,
- onError: injectLambdaContextAfterOrOnError,
+ before: onBefore,
+ after: onAfter,
+ onError,
};
};
diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts
index 4ec8fb1061..d8b422f6ef 100644
--- a/packages/logger/tests/unit/logBuffer.test.ts
+++ b/packages/logger/tests/unit/logBuffer.test.ts
@@ -1,8 +1,10 @@
import context from '@aws-lambda-powertools/testing-utils/context';
import type { Context } from 'aws-lambda';
+import middy from 'middy5';
import { type Mock, beforeEach, describe, expect, it, vi } from 'vitest';
import { Logger } from '../../src/Logger.js';
import { LogLevel, UncaughtErrorLogMessage } from '../../src/constants.js';
+import { injectLambdaContext } from '../../src/middleware/middy.js';
import type { ConstructorOptions } from '../../src/types/Logger.js';
describe('Buffer logs', () => {
@@ -227,6 +229,41 @@ describe('Buffer logs', () => {
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(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);
+ });
+ it('flushes the buffer when an uncaught error is thrown in a middy', async () => {
+ // Prepare
+ const logger = new Logger({ logBufferOptions: { enabled: true } });
+
+ const handlerFn = async (_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 handler = middy()
+ .use(injectLambdaContext(logger, { flushBufferOnUncaughtError: true }))
+ .handler(handlerFn);
+
// Act & Assess
await expect(() =>
handler(
From bf767927354ba3935dac5ad4f2e1231cde79d387 Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Mon, 3 Mar 2025 14:58:22 +0000
Subject: [PATCH 3/8] Add test for case where clearBuffer is called without a
traceId
---
packages/logger/tests/unit/logBuffer.test.ts | 11 +++++++++++
1 file changed, 11 insertions(+)
diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts
index d8b422f6ef..c993cc33ae 100644
--- a/packages/logger/tests/unit/logBuffer.test.ts
+++ b/packages/logger/tests/unit/logBuffer.test.ts
@@ -197,6 +197,17 @@ describe('Buffer logs', () => {
);
});
+ it('it safely short circuits when clearBuffer is called without a trace id', () => {
+ // Prepare
+ process.env._X_AMZN_TRACE_ID = undefined;
+ const logger = new Logger({
+ logLevel: LogLevel.ERROR,
+ logBufferOptions: { enabled: true, bufferAtVerbosity: LogLevel.DEBUG },
+ });
+
+ // Assess
+ expect(() => logger.clearBuffer()).not.toThrow();
+ });
it('it flushes the buffer when an error in logged', () => {
// Prepare
const logger = new Logger({
From 9498e843d58d719cde12cd40e34a62e8aebe0e8d Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Mon, 3 Mar 2025 15:02:07 +0000
Subject: [PATCH 4/8] Test clearBuffer
---
packages/logger/tests/unit/logBuffer.test.ts | 17 +++++++++++++++++
1 file changed, 17 insertions(+)
diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts
index c993cc33ae..170570b582 100644
--- a/packages/logger/tests/unit/logBuffer.test.ts
+++ b/packages/logger/tests/unit/logBuffer.test.ts
@@ -208,6 +208,23 @@ describe('Buffer logs', () => {
// Assess
expect(() => logger.clearBuffer()).not.toThrow();
});
+
+ it('it clears the buffer', () => {
+ // Prepare
+ const logger = new Logger({
+ logLevel: LogLevel.ERROR,
+ logBufferOptions: { enabled: true, bufferAtVerbosity: LogLevel.DEBUG },
+ });
+
+ // Arrange
+ logger.debug('This is a log message');
+ logger.clearBuffer();
+
+ logger.flushBuffer();
+
+ // Assess
+ expect(console.debug).not.toBeCalled;
+ });
it('it flushes the buffer when an error in logged', () => {
// Prepare
const logger = new Logger({
From 02e1440d6d1de29fe74561b2749c3b6cf470c4bb Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Tue, 4 Mar 2025 10:46:50 +0000
Subject: [PATCH 5/8] Incorporate feedback
---
packages/logger/src/middleware/middy.ts | 23 ++--
packages/logger/tests/unit/logBuffer.test.ts | 126 +++++++++----------
2 files changed, 68 insertions(+), 81 deletions(-)
diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts
index 2af8559d54..45ccb82d70 100644
--- a/packages/logger/src/middleware/middy.ts
+++ b/packages/logger/src/middleware/middy.ts
@@ -77,11 +77,11 @@ const injectLambdaContext = (
const setCleanupFunction = (request: MiddyLikeRequest): void => {
request.internal = {
...request.internal,
- [LOGGER_KEY]: onAfter,
+ [LOGGER_KEY]: after,
};
};
- const onBefore = async (request: MiddyLikeRequest): Promise<void> => {
+ const before = async (request: MiddyLikeRequest): Promise<void> => {
for (const logger of loggers) {
if (isResetStateEnabled) {
setCleanupFunction(request);
@@ -98,18 +98,17 @@ const injectLambdaContext = (
}
};
- const onAfter = async (): Promise<void> => {
- if (isResetStateEnabled) {
- for (const logger of loggers) {
- logger.resetKeys();
- }
- }
-
+ const after = async (): Promise<void> => {
for (const logger of loggers) {
logger.clearBuffer();
+
+ if (isResetStateEnabled) {
+ logger.resetKeys();
+ }
}
};
- const onError = async ({ error }): Promise<void> => {
+
+ const onError = async ({ error }: { error: unknown }): Promise<void> => {
if (options?.flushBufferOnUncaughtError) {
for (const logger of loggers) {
logger.flushBuffer();
@@ -122,8 +121,8 @@ const injectLambdaContext = (
};
return {
- before: onBefore,
- after: onAfter,
+ before,
+ after,
onError,
};
};
diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts
index 170570b582..675dae48be 100644
--- a/packages/logger/tests/unit/logBuffer.test.ts
+++ b/packages/logger/tests/unit/logBuffer.test.ts
@@ -243,74 +243,62 @@ describe('Buffer logs', () => {
expect(console.error).toBeCalledTimes(1);
});
- it('flushes the buffer when an uncaught error is thrown', 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');
- }
+ it.each([
+ {
+ handlerFactory: (logger: Logger) =>
+ middy()
+ .use(
+ injectLambdaContext(logger, { flushBufferOnUncaughtError: true })
+ )
+ .handler(async () => {
+ logger.debug('This is a log message');
+ logger.info('This is an info message');
+ throw new Error('This is an error');
+ }),
+ case: 'middleware',
+ },
+ {
+ handlerFactory: (logger: Logger) => {
+ 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();
+ return lambda.handler.bind(lambda);
+ },
+ case: 'decorator',
+ },
+ ])(
+ 'flushes the buffer when an uncaught error is thrown ($case)',
+ async ({ handlerFactory }) => {
+ // Prepare
+ const logger = new Logger({ logBufferOptions: { enabled: true } });
+ const handler = handlerFactory(logger);
+
+ // Act & Assess
+ await expect(() =>
+ handler(
+ {
+ foo: 'bar',
+ },
+ context
+ )
+ ).rejects.toThrow(new Error('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);
}
- 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(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);
- });
- it('flushes the buffer when an uncaught error is thrown in a middy', async () => {
- // Prepare
- const logger = new Logger({ logBufferOptions: { enabled: true } });
-
- const handlerFn = async (_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 handler = middy()
- .use(injectLambdaContext(logger, { flushBufferOnUncaughtError: true }))
- .handler(handlerFn);
-
- // Act & Assess
- await expect(() =>
- handler(
- {
- foo: 'bar',
- },
- context
- )
- ).rejects.toThrow(new Error('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 1f0b0acdfdbbd18e45642e6b28ac4b112262df16 Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Tue, 4 Mar 2025 11:33:16 +0000
Subject: [PATCH 6/8] Clear buffer if not flushed on error
---
packages/logger/src/Logger.ts | 2 ++
packages/logger/src/middleware/middy.ts | 6 ++++--
2 files changed, 6 insertions(+), 2 deletions(-)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index 1c4e958120..57c861478e 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -449,6 +449,8 @@ class Logger extends Utility implements LoggerInterface {
message: UncaughtErrorLogMessage,
error,
});
+ } else {
+ loggerRef.clearBuffer();
}
throw error;
/* v8 ignore next */
diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts
index 45ccb82d70..f85b1af9f8 100644
--- a/packages/logger/src/middleware/middy.ts
+++ b/packages/logger/src/middleware/middy.ts
@@ -109,13 +109,15 @@ const injectLambdaContext = (
};
const onError = async ({ error }: { error: unknown }): Promise<void> => {
- if (options?.flushBufferOnUncaughtError) {
- for (const logger of loggers) {
+ for (const logger of loggers) {
+ if (options?.flushBufferOnUncaughtError) {
logger.flushBuffer();
logger.error({
message: UncaughtErrorLogMessage,
error,
});
+ } else {
+ logger.clearBuffer();
}
}
};
From c04fda5104ec8717ec17421a2cd42dd7e0a143c0 Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Tue, 4 Mar 2025 11:50:40 +0000
Subject: [PATCH 7/8] Add tests for clearing buffer on uncaught error when
flushBufferOnUncaughtError is false
---
packages/logger/tests/unit/logBuffer.test.ts | 51 ++++++++++++++++++++
1 file changed, 51 insertions(+)
diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts
index 675dae48be..9e3000624d 100644
--- a/packages/logger/tests/unit/logBuffer.test.ts
+++ b/packages/logger/tests/unit/logBuffer.test.ts
@@ -301,4 +301,55 @@ describe('Buffer logs', () => {
expect(console.debug).toHaveBeenCalledBefore(console.error as Mock);
}
);
+ it.each([
+ {
+ handlerFactory: (logger: Logger) =>
+ middy()
+ .use(
+ injectLambdaContext(logger, { flushBufferOnUncaughtError: false })
+ )
+ .handler(async () => {
+ logger.debug('This is a log message');
+ logger.info('This is an info message');
+ throw new Error('This is an error');
+ }),
+ case: 'middleware',
+ },
+ {
+ handlerFactory: (logger: Logger) => {
+ class TestClass {
+ @logger.injectLambdaContext({ flushBufferOnUncaughtError: false })
+ 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();
+ return lambda.handler.bind(lambda);
+ },
+ case: 'decorator',
+ },
+ ])(
+ 'clears the buffer when an uncaught error is thrown and flushBufferOnUncaughtError is false ($case)',
+ async ({ handlerFactory }) => {
+ // Prepare
+ const logger = new Logger({ logBufferOptions: { enabled: true } });
+ const handler = handlerFactory(logger);
+
+ // Act & Assess
+ await expect(() =>
+ handler(
+ {
+ foo: 'bar',
+ },
+ context
+ )
+ ).rejects.toThrow(new Error('This is an error'));
+
+ // Assess
+ expect(console.debug).not.toBeCalled;
+ expect(console.info).not.toBeCalled;
+ }
+ );
});
From 9d324bcdba57b2a871bb0911c38aff8e3b740993 Mon Sep 17 00:00:00 2001
From: Connor Kirkpatrick <ckp@amazon.com>
Date: Tue, 4 Mar 2025 12:56:06 +0000
Subject: [PATCH 8/8] Use finally block
---
packages/logger/src/Logger.ts | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index 57c861478e..5efc099f45 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -449,13 +449,12 @@ class Logger extends Utility implements LoggerInterface {
message: UncaughtErrorLogMessage,
error,
});
- } else {
- loggerRef.clearBuffer();
}
throw error;
/* v8 ignore next */
} finally {
if (options?.clearState || options?.resetKeys) loggerRef.resetKeys();
+ loggerRef.clearBuffer();
}
};
};