From 6c70a0bcf160c5c71f01381b29679bda1d4f1992 Mon Sep 17 00:00:00 2001
From: Andrea Amorosi <dreamorosi@gmail.com>
Date: Fri, 8 Jul 2022 08:45:30 +0200
Subject: [PATCH 1/5] fix: POWERTOOLS_LOGGER_LOG_EVENT precedence is respected
---
packages/logger/src/Logger.ts | 16 +-
packages/logger/src/middleware/middy.ts | 5 +-
.../tests/unit/middleware/middy.test.ts | 153 ++++++++++++++----
3 files changed, 139 insertions(+), 35 deletions(-)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index 2d84eebd81..7e02f2f96e 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -636,6 +636,19 @@ class Logger extends Utility implements ClassThatLogs {
this.envVarsService = new EnvironmentVariablesService();
}
+ /**
+ * If the log event feature is enabled via env variable, it sets a property that tracks whether
+ * the event passed to the Lambda function handler should be logged or not.
+ *
+ * @private
+ * @returns {void}
+ */
+ private setLogEvent(): void {
+ if (this.getEnvVarsService().getLogEvent()) {
+ this.logEvent = true;
+ }
+ }
+
/**
* It sets the log formatter instance, in charge of giving a custom format
* to the structured logs
@@ -716,7 +729,8 @@ class Logger extends Utility implements ClassThatLogs {
this.setLogsSampled();
this.setLogFormatter(logFormatter);
this.setPowertoolLogData(serviceName, environment);
-
+ this.setLogEvent();
+
this.addPersistentLogAttributes(persistentLogAttributes);
return this;
diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts
index 34af3ac349..02ef923c0c 100644
--- a/packages/logger/src/middleware/middy.ts
+++ b/packages/logger/src/middleware/middy.ts
@@ -38,9 +38,8 @@ const injectLambdaContext = (target: Logger | Logger[], options?: HandlerOptions
if (options && options.clearState === true) {
persistentAttributes.push({ ...logger.getPersistentLogAttributes() });
}
- if (options) {
- logger.logEventIfEnabled(request.event, options.logEvent);
- }
+ const logEvent = options ? options.hasOwnProperty('logEvent') ? options.logEvent : undefined : undefined;
+ logger.logEventIfEnabled(request.event, logEvent);
});
};
diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts
index 7c596182a3..950f66946e 100644
--- a/packages/logger/tests/unit/middleware/middy.test.ts
+++ b/packages/logger/tests/unit/middleware/middy.test.ts
@@ -153,6 +153,64 @@ describe('Middy middleware', () => {
});
});
+
+ });
+
+ describe('Feature: clear state', () => {
+
+ test('when enabled, the persistent log attributes added in the handler are removed after the handler\'s code is executed', async () => {
+
+ // Prepare
+ const logger = new Logger({
+ logLevel: 'DEBUG',
+ persistentLogAttributes: {
+ foo: 'bar',
+ biz: 'baz'
+ }
+ });
+ const context = {
+ callbackWaitsForEmptyEventLoop: true,
+ functionVersion: '$LATEST',
+ functionName: 'foo-bar-function',
+ memoryLimitInMB: '128',
+ logGroupName: '/aws/lambda/foo-bar-function',
+ logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456',
+ invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ awsRequestId: 'abcdef123456abcdef123456',
+ getRemainingTimeInMillis: () => 1234,
+ done: () => console.log('Done!'),
+ fail: () => console.log('Failed!'),
+ succeed: () => console.log('Succeeded!'),
+ };
+
+ const lambdaHandler = (event: { user_id: string }): void => {
+ // Only add these persistent for the scope of this lambda handler
+ logger.appendKeys({
+ details: { user_id: event['user_id'] }
+ });
+ logger.debug('This is a DEBUG log with the user_id');
+ logger.debug('This is another DEBUG log with the user_id');
+ };
+ const handler = middy(lambdaHandler).use(injectLambdaContext(logger, { clearState: true }));
+ const persistentAttribs = { ...logger.getPersistentLogAttributes() };
+
+ // Act
+ await handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!'));
+ const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() };
+
+ // Assess
+ expect(persistentAttribs).toEqual({
+ foo: 'bar',
+ biz: 'baz'
+ });
+ expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs);
+
+ });
+
+ });
+
+ describe('Feature: log event', () => {
+
test('when a logger is passed with option logEvent set to true, it logs the event', async () => {
// Prepare
@@ -203,7 +261,7 @@ describe('Middy middleware', () => {
});
- test('when a logger is passed with option logEvent set to true, it logs the event', async () => {
+ test('when a logger is passed with option logEvent set to true, while also having a custom configService, it logs the event', async () => {
// Prepare
const configService: ConfigServiceInterface = {
@@ -227,7 +285,6 @@ describe('Middy middleware', () => {
},
};
- // Prepare
const logger = new Logger({
customConfigService: configService,
@@ -278,20 +335,19 @@ describe('Middy middleware', () => {
});
- });
-
- describe('Feature: clear state', () => {
-
- test('when enabled, the persistent log attributes added in the handler are removed after the handler\'s code is executed', async () => {
+ test('when a logger is passed without options, but POWERTOOLS_LOGGER_LOG_EVENT env var is set to true, it logs the event', async () => {
// Prepare
- const logger = new Logger({
- logLevel: 'DEBUG',
- persistentLogAttributes: {
- foo: 'bar',
- biz: 'baz'
- }
- });
+ process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true';
+ const logger = new Logger();
+ const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation();
+ const lambdaHandler = (): void => {
+ logger.info('This is an INFO log with some context');
+ };
+ const handler = middy(lambdaHandler).use(injectLambdaContext(logger));
+ const event = { foo: 'bar' };
+ const getRandomInt = (): number => Math.floor(Math.random() * 1000000000);
+ const awsRequestId = getRandomInt().toString();
const context = {
callbackWaitsForEmptyEventLoop: true,
functionVersion: '$LATEST',
@@ -300,34 +356,69 @@ describe('Middy middleware', () => {
logGroupName: '/aws/lambda/foo-bar-function',
logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456',
invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
- awsRequestId: 'abcdef123456abcdef123456',
+ awsRequestId: awsRequestId,
getRemainingTimeInMillis: () => 1234,
done: () => console.log('Done!'),
fail: () => console.log('Failed!'),
succeed: () => console.log('Succeeded!'),
};
- const lambdaHandler = (event: { user_id: string }): void => {
- // Only add these persistent for the scope of this lambda handler
- logger.appendKeys({
- details: { user_id: event['user_id'] }
- });
- logger.debug('This is a DEBUG log with the user_id');
- logger.debug('This is another DEBUG log with the user_id');
+ // Act
+ await handler(event, context, () => console.log('Lambda invoked!'));
+
+ // Assess
+ expect(consoleSpy).toBeCalledTimes(2);
+ expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({
+ cold_start: true,
+ function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ function_memory_size: 128,
+ function_name: 'foo-bar-function',
+ function_request_id: awsRequestId,
+ level: 'INFO',
+ message: 'Lambda invocation event',
+ service: 'hello-world',
+ timestamp: '2016-06-20T12:08:10.000Z',
+ xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
+ event: {
+ foo: 'bar'
+ }
+ }));
+
+ });
+
+ test('when a logger is passed with option logEvent set to false, but POWERTOOLS_LOGGER_LOG_EVENT env var is set to true, it does not log the event', async () => {
+
+ // Prepare
+ process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true';
+ const logger = new Logger();
+ const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation();
+ const lambdaHandler = (): void => {
+ logger.info('This is an INFO log with some context');
+ };
+ const handler = middy(lambdaHandler).use(injectLambdaContext(logger, { logEvent: false }));
+ const event = { foo: 'bar' };
+ const getRandomInt = (): number => Math.floor(Math.random() * 1000000000);
+ const awsRequestId = getRandomInt().toString();
+ const context = {
+ callbackWaitsForEmptyEventLoop: true,
+ functionVersion: '$LATEST',
+ functionName: 'foo-bar-function',
+ memoryLimitInMB: '128',
+ logGroupName: '/aws/lambda/foo-bar-function',
+ logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456',
+ invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ awsRequestId: awsRequestId,
+ getRemainingTimeInMillis: () => 1234,
+ done: () => console.log('Done!'),
+ fail: () => console.log('Failed!'),
+ succeed: () => console.log('Succeeded!'),
};
- const handler = middy(lambdaHandler).use(injectLambdaContext(logger, { clearState: true }));
- const persistentAttribs = { ...logger.getPersistentLogAttributes() };
// Act
- await handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!'));
- const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() };
+ await handler(event, context, () => console.log('Lambda invoked!'));
// Assess
- expect(persistentAttribs).toEqual({
- foo: 'bar',
- biz: 'baz'
- });
- expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs);
+ expect(consoleSpy).toBeCalledTimes(1);
});
From a034a6063b5dbe1f1a56eed30e79781d53fa7259 Mon Sep 17 00:00:00 2001
From: Andrea Amorosi <dreamorosi@gmail.com>
Date: Fri, 8 Jul 2022 09:10:11 +0200
Subject: [PATCH 2/5] fix: decorator logic
---
packages/logger/src/Logger.ts | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index 7e02f2f96e..93db493e88 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -292,9 +292,8 @@ class Logger extends Utility implements ClassThatLogs {
}
this.addContext(context);
- if (options) {
- this.logEventIfEnabled(event, options.logEvent);
- }
+ const logEvent = options ? options.hasOwnProperty('logEvent') ? options.logEvent : undefined : undefined;
+ this.logEventIfEnabled(event, logEvent);
/* eslint-disable @typescript-eslint/no-non-null-assertion */
const result = originalMethod!.apply(target, [ event, context, callback ]);
From 0dd45683090525bc6e9001bf1ea2f37582c9545e Mon Sep 17 00:00:00 2001
From: Andrea Amorosi <dreamorosi@gmail.com>
Date: Fri, 8 Jul 2022 09:21:57 +0200
Subject: [PATCH 3/5] chore: added unit test cases for decorator
---
packages/logger/tests/unit/Logger.test.ts | 87 +++++++++++++++++++++++
1 file changed, 87 insertions(+)
diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts
index 8fe30c7bc2..88b628453e 100644
--- a/packages/logger/tests/unit/Logger.test.ts
+++ b/packages/logger/tests/unit/Logger.test.ts
@@ -982,6 +982,93 @@ describe('Class: Logger', () => {
});
+ test('when used as decorator with the log event flag enabled, it logs the event', async () => {
+
+ // Prepare
+ const logger = new Logger({
+ logLevel: 'DEBUG',
+ });
+ const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation();
+
+ type CustomEvent = { user_id: string };
+
+ class LambdaFunction implements LambdaInterface {
+
+ @logger.injectLambdaContext({ logEvent: true })
+ // eslint-disable-next-line @typescript-eslint/ban-ts-comment
+ // @ts-ignore
+ public handler<TResult>(_event: CustomEvent, _context: Context, _callback: Callback<TResult>): void | Promise<TResult> {
+ return;
+ }
+ }
+
+ // Act
+ await new LambdaFunction().handler({ user_id: '123456' }, dummyContext, () => console.log('Lambda invoked!'));
+
+ // Assess
+ expect(consoleSpy).toBeCalledTimes(1);
+ expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({
+ cold_start: true,
+ function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ function_memory_size: 128,
+ function_name: 'foo-bar-function',
+ function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
+ level: 'INFO',
+ message: 'Lambda invocation event',
+ service: 'hello-world',
+ timestamp: '2016-06-20T12:08:10.000Z',
+ xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
+ event: {
+ user_id: '123456'
+ }
+ }));
+
+ });
+
+ test('when used as decorator without options, but POWERTOOLS_LOGGER_LOG_EVENT env var is set to true, it logs the event', async () => {
+
+ // Prepare
+ process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true';
+ const logger = new Logger({
+ logLevel: 'DEBUG',
+ });
+ const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation();
+
+ type CustomEvent = { user_id: string };
+
+ class LambdaFunction implements LambdaInterface {
+
+ @logger.injectLambdaContext()
+ // eslint-disable-next-line @typescript-eslint/ban-ts-comment
+ // @ts-ignore
+ public handler<TResult>(_event: CustomEvent, _context: Context, _callback: Callback<TResult>): void | Promise<TResult> {
+ return;
+ }
+ }
+
+ // Act
+ await new LambdaFunction().handler({ user_id: '123456' }, dummyContext, () => console.log('Lambda invoked!'));
+
+ // Assess
+ expect(consoleSpy).toBeCalledTimes(1);
+ expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({
+ cold_start: true,
+ function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ function_memory_size: 128,
+ function_name: 'foo-bar-function',
+ function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
+ level: 'INFO',
+ message: 'Lambda invocation event',
+ service: 'hello-world',
+ timestamp: '2016-06-20T12:08:10.000Z',
+ xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
+ event: {
+ user_id: '123456'
+ }
+ }));
+
+ });
+
});
describe('Method: refreshSampleRateCalculation', () => {
From 076660c6636c83452a4d4b53c673025ce5cb6cf6 Mon Sep 17 00:00:00 2001
From: Andrea Amorosi <dreamorosi@gmail.com>
Date: Mon, 11 Jul 2022 09:29:19 +0100
Subject: [PATCH 4/5] chore: added e2e test cases
---
...ntEnvVarSetting.middy.test.FunctionCode.ts | 16 +++
.../e2e/logEventEnvVarSetting.middy.test.ts | 110 ++++++++++++++++++
2 files changed, 126 insertions(+)
create mode 100644 packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts
create mode 100644 packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
diff --git a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts
new file mode 100644
index 0000000000..6d412daf06
--- /dev/null
+++ b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts
@@ -0,0 +1,16 @@
+import { injectLambdaContext, Logger } from '../../src';
+import { Context } from 'aws-lambda';
+import middy from '@middy/core';
+
+type LambdaEvent = {
+ invocation: number
+};
+
+const logger = new Logger();
+
+const testFunction = async (event: LambdaEvent, context: Context): Promise<{requestId: string}> => ({
+ requestId: context.awsRequestId,
+});
+
+export const handler = middy(testFunction)
+ .use(injectLambdaContext(logger));
diff --git a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
new file mode 100644
index 0000000000..c769fdcb0f
--- /dev/null
+++ b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
@@ -0,0 +1,110 @@
+// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
+// SPDX-License-Identifier: MIT-0
+
+/**
+ * Test logger basic features
+ *
+ * @group e2e/logger/logEventEnvVarSetting
+ */
+
+import path from 'path';
+import { App, Stack } from 'aws-cdk-lib';
+import { v4 } from 'uuid';
+import {
+ createStackWithLambdaFunction,
+ generateUniqueName,
+ invokeFunction,
+ isValidRuntimeKey
+} from '../../../commons/tests/utils/e2eUtils';
+import { InvocationLogs } from '../../../commons/tests/utils/InvocationLogs';
+import { deployStack, destroyStack } from '../../../commons/tests/utils/cdk-cli';
+import {
+ RESOURCE_NAME_PREFIX,
+ STACK_OUTPUT_LOG_GROUP,
+ SETUP_TIMEOUT,
+ TEST_CASE_TIMEOUT,
+ TEARDOWN_TIMEOUT
+} from './constants';
+
+const runtime: string = process.env.RUNTIME || 'nodejs16x';
+
+if (!isValidRuntimeKey(runtime)) {
+ throw new Error(`Invalid runtime key value: ${runtime}`);
+}
+
+const uuid = v4();
+const stackName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'LogEventEnvVarSetting-Middy');
+const functionName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'LogEventEnvVarSetting-Middy');
+const lambdaFunctionCodeFile = 'logEventEnvVarSetting.middy.test.FunctionCode.ts';
+
+const integTestApp = new App();
+let logGroupName: string; // We do not know it until deployment
+let stack: Stack;
+
+describe(`logger E2E tests log event via env var setting (middy) for runtime: ${runtime}`, () => {
+
+ let invocationLogs: InvocationLogs[];
+
+ beforeAll(async () => {
+ // Create and deploy a stack with AWS CDK
+ stack = createStackWithLambdaFunction({
+ app: integTestApp,
+ stackName: stackName,
+ functionName: functionName,
+ functionEntry: path.join(__dirname, lambdaFunctionCodeFile),
+ environment: {
+ LOG_LEVEL: 'INFO',
+ POWERTOOLS_SERVICE_NAME: 'logger-e2e-testing',
+ UUID: uuid,
+
+ // Enabling the logger to log events via env var
+ POWERTOOLS_LOGGER_LOG_EVENT: 'true',
+ },
+ logGroupOutputKey: STACK_OUTPUT_LOG_GROUP,
+ runtime: runtime,
+ });
+
+ const result = await deployStack(integTestApp, stack);
+ logGroupName = result.outputs[STACK_OUTPUT_LOG_GROUP];
+
+ // Invoke the function twice (one for cold start, another for warm start)
+ invocationLogs = await invokeFunction(functionName, 2, 'SEQUENTIAL');
+
+ console.log('logGroupName', logGroupName);
+
+ }, SETUP_TIMEOUT);
+
+ describe('Log event', () => {
+
+ it('should log the event on the first invocation', async () => {
+ const firstInvocationMessages = invocationLogs[0].getAllFunctionLogs();
+ let eventLoggedInFirstInvocation = false;
+ for (const message of firstInvocationMessages) {
+ if (message.includes(`event`)) {
+ eventLoggedInFirstInvocation = true;
+ expect(message).toContain(`"event":{"invocation":0}`);
+ }
+ }
+
+ const secondInvocationMessages = invocationLogs[1].getAllFunctionLogs();
+ let eventLoggedInSecondInvocation = false;
+ for (const message of secondInvocationMessages) {
+ if (message.includes(`event`)) {
+ eventLoggedInSecondInvocation = true;
+ expect(message).toContain(`"event":{"invocation":1}`);
+ }
+ }
+
+ expect(eventLoggedInFirstInvocation).toBe(true);
+ expect(eventLoggedInSecondInvocation).toBe(true);
+
+ }, TEST_CASE_TIMEOUT);
+
+ });
+
+ afterAll(async () => {
+ if (!process.env.DISABLE_TEARDOWN) {
+ await destroyStack(integTestApp, stack);
+ }
+ }, TEARDOWN_TIMEOUT);
+});
From 00f5f73b82cc656e93771adc907d2397b199ce1f Mon Sep 17 00:00:00 2001
From: Andrea Amorosi <dreamorosi@gmail.com>
Date: Mon, 11 Jul 2022 15:47:43 +0100
Subject: [PATCH 5/5] chore: address review comments
---
packages/logger/src/Logger.ts | 7 +++++--
packages/logger/src/middleware/middy.ts | 8 ++++++--
.../e2e/logEventEnvVarSetting.middy.test.ts | 2 +-
.../logger/tests/unit/middleware/middy.test.ts | 17 ++++++++++++++---
4 files changed, 26 insertions(+), 8 deletions(-)
diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts
index 93db493e88..f6e05cdf63 100644
--- a/packages/logger/src/Logger.ts
+++ b/packages/logger/src/Logger.ts
@@ -292,8 +292,11 @@ class Logger extends Utility implements ClassThatLogs {
}
this.addContext(context);
- const logEvent = options ? options.hasOwnProperty('logEvent') ? options.logEvent : undefined : undefined;
- this.logEventIfEnabled(event, logEvent);
+ let shouldLogEvent = undefined;
+ if ( options && options.hasOwnProperty('logEvent') ) {
+ shouldLogEvent = options.logEvent;
+ }
+ this.logEventIfEnabled(event, shouldLogEvent);
/* eslint-disable @typescript-eslint/no-non-null-assertion */
const result = originalMethod!.apply(target, [ event, context, callback ]);
diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts
index 02ef923c0c..6800686d18 100644
--- a/packages/logger/src/middleware/middy.ts
+++ b/packages/logger/src/middleware/middy.ts
@@ -38,8 +38,12 @@ const injectLambdaContext = (target: Logger | Logger[], options?: HandlerOptions
if (options && options.clearState === true) {
persistentAttributes.push({ ...logger.getPersistentLogAttributes() });
}
- const logEvent = options ? options.hasOwnProperty('logEvent') ? options.logEvent : undefined : undefined;
- logger.logEventIfEnabled(request.event, logEvent);
+
+ let shouldLogEvent = undefined;
+ if ( options && options.hasOwnProperty('logEvent') ) {
+ shouldLogEvent = options.logEvent;
+ }
+ logger.logEventIfEnabled(request.event, shouldLogEvent);
});
};
diff --git a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
index c769fdcb0f..b054d0bd75 100644
--- a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
+++ b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts
@@ -76,7 +76,7 @@ describe(`logger E2E tests log event via env var setting (middy) for runtime: ${
describe('Log event', () => {
- it('should log the event on the first invocation', async () => {
+ it('should log the event at both invocations', async () => {
const firstInvocationMessages = invocationLogs[0].getAllFunctionLogs();
let eventLoggedInFirstInvocation = false;
for (const message of firstInvocationMessages) {
diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts
index 950f66946e..d6eb08b0f6 100644
--- a/packages/logger/tests/unit/middleware/middy.test.ts
+++ b/packages/logger/tests/unit/middleware/middy.test.ts
@@ -158,7 +158,7 @@ describe('Middy middleware', () => {
describe('Feature: clear state', () => {
- test('when enabled, the persistent log attributes added in the handler are removed after the handler\'s code is executed', async () => {
+ test('when enabled, the persistent log attributes added within the handler scope are removed after the invocation ends', async () => {
// Prepare
const logger = new Logger({
@@ -393,7 +393,7 @@ describe('Middy middleware', () => {
const logger = new Logger();
const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation();
const lambdaHandler = (): void => {
- logger.info('This is an INFO log with some context');
+ logger.info('This is an INFO log');
};
const handler = middy(lambdaHandler).use(injectLambdaContext(logger, { logEvent: false }));
const event = { foo: 'bar' };
@@ -419,7 +419,18 @@ describe('Middy middleware', () => {
// Assess
expect(consoleSpy).toBeCalledTimes(1);
-
+ expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({
+ cold_start: true,
+ function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function',
+ function_memory_size: 128,
+ function_name: 'foo-bar-function',
+ function_request_id: awsRequestId,
+ level: 'INFO',
+ message: 'This is an INFO log',
+ service: 'hello-world',
+ timestamp: '2016-06-20T12:08:10.000Z',
+ xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
+ }));
});
});