diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index 4b0775421d..ae1bc74172 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -3,8 +3,10 @@ * * @group unit/logger/all */ - -import { ContextExamples as dummyContext, Events as dummyEvent, LambdaInterface } from '@aws-lambda-powertools/commons'; +import { + ContextExamples as dummyContext, + Events as dummyEvent, LambdaInterface +} from '@aws-lambda-powertools/commons'; import { createLogger, Logger } from '../../src'; import { EnvironmentVariablesService } from '../../src/config'; import { PowertoolLogFormatter } from '../../src/formatter'; @@ -16,6 +18,7 @@ const mockDate = new Date(1466424490000); const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); describe('Class: Logger', () => { + const ENVIRONMENT_VARIABLES = process.env; const context = dummyContext.helloworldContext; const event = dummyEvent.Custom.CustomEvent; @@ -45,6 +48,7 @@ describe('Class: Logger', () => { ) => { describe('Feature: log level', () => { + const methodOfLogger = method as keyof ClassThatLogs; test('when the Logger\'s log level is DEBUG, it ' + debugAction + ' print to stdout', () => { @@ -207,7 +211,7 @@ describe('Class: Logger', () => { }); - describe('Feature: capture Lambda context information and add it in the printed logs', () => { + describe('Feature: inject context', () => { const methodOfLogger = method as keyof ClassThatLogs; @@ -231,6 +235,7 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', })); + }); test('when the Lambda context is captured, it returns a valid ' + method.toUpperCase() + ' log', () => { @@ -398,7 +403,9 @@ describe('Class: Logger', () => { } } })); + }); + }); describe('Feature: persistent log attributes', () => { @@ -433,6 +440,7 @@ describe('Class: Logger', () => { aws_account_id: '123456789012', aws_region: 'eu-west-1', })); + }); }); @@ -463,6 +471,7 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', })); + }); test('when the `_X_AMZN_TRACE_ID` environment variable is NOT set it parses it correctly and adds the Trace ID to the log', () => { @@ -487,6 +496,7 @@ describe('Class: Logger', () => { service: 'hello-world', timestamp: '2016-06-20T12:08:10.000Z', })); + }); }); @@ -533,7 +543,7 @@ describe('Class: Logger', () => { }); - test('when a logged item has BigInt value, it doen\'t throw TypeError', () => { + test('when a logged item has BigInt value, it doesn\'t throw TypeError', () => { // Prepare const logger = new Logger(); @@ -600,28 +610,13 @@ describe('Class: Logger', () => { describe('Method: addContext', () => { - const baseContext = { - callbackWaitsForEmptyEventLoop: true, - functionVersion: '$LATEST', - functionName: 'foo-bar-function-with-cold-start', - memoryLimitInMB: '128', - logGroupName: '/aws/lambda/foo-bar-function-with-cold-start', - logStreamName: '2021/03/09/[$LATEST]1-5759e988-bd862e3fe1be46a994272793', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function-with-cold-start', - awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - getRemainingTimeInMillis: () => 1234, - done: () => console.log('Done!'), - fail: () => console.log('Failed!'), - succeed: () => console.log('Succeeded!'), - }; - - test('when called during a COLD START invocation, it populates the logger\'s PowertoolLogData object with coldstart set to true', () => { + test('when called during a cold start invocation, it populates the logger\'s PowertoolLogData object with coldStart set to TRUE', () => { // Prepare const logger = new Logger(); // Act - logger.addContext(baseContext); + logger.addContext(context); // Assess expect(logger).toEqual({ @@ -648,23 +643,25 @@ describe('Class: Logger', () => { lambdaContext: { awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', coldStart: true, - functionName: 'foo-bar-function-with-cold-start', + functionName: 'foo-bar-function', functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function-with-cold-start', + invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', memoryLimitInMB: 128, }, sampleRateValue: undefined, serviceName: 'hello-world', }, + }); + }); test('when called with a context object, the object is not mutated', () => { // Prepare const logger = new Logger(); - const context1 = { ...baseContext, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; - const context2 = { ...baseContext, awsRequestId: 'd40c98a9-91c4-478c-a179-433c4b978289' }; + const context1 = { ...context, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; + const context2 = { ...context, awsRequestId: 'd40c98a9-91c4-478c-a179-433c4b978289' }; // Act logger.addContext(context1); @@ -673,14 +670,15 @@ describe('Class: Logger', () => { // Assess expect(context1.awsRequestId).toEqual('c6af9ac6-7b61-11e6-9a41-93e812345678'); expect(context2.awsRequestId).toEqual('d40c98a9-91c4-478c-a179-433c4b978289'); + }); test('when called multiple times, the newer values override earlier values', () => { // Prepare const logger = new Logger(); - const context1 = { ...baseContext, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; - const context2 = { ...baseContext, awsRequestId: 'd40c98a9-91c4-478c-a179-433c4b978289' }; + const context1 = { ...context, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; + const context2 = { ...context, awsRequestId: 'd40c98a9-91c4-478c-a179-433c4b978289' }; // Act logger.addContext(context1); @@ -696,7 +694,9 @@ describe('Class: Logger', () => { }) }) ); + }); + }); describe('Method: appendKeys', () => { @@ -727,6 +727,7 @@ describe('Class: Logger', () => { }, }, })); + }); test('when called with user-provided attribute objects, the objects are not mutated', () => { @@ -743,6 +744,7 @@ describe('Class: Logger', () => { // Assess expect(attributes1).toEqual({ keyOne: 'abc' }); expect(attributes2).toEqual({ keyTwo: 'def' }); + }); test('when called multiple times, the newer values override earlier values', () => { @@ -764,7 +766,9 @@ describe('Class: Logger', () => { duplicateKey: 'two' } })); + }); + }); describe('Method: removeKeys', () => { @@ -794,6 +798,7 @@ describe('Class: Logger', () => { }, }, })); + }); test('when called with non-existing keys, the logger\'s property persistentLogAttributes is not mutated and it does not throw an error', () => { @@ -825,6 +830,7 @@ describe('Class: Logger', () => { }, }, })); + }); test('when called multiple times with the same keys, the outcome is the same', () => { @@ -853,6 +859,7 @@ describe('Class: Logger', () => { }, }, })); + }); }); @@ -860,11 +867,10 @@ describe('Class: Logger', () => { describe('Method: injectLambdaContext', () => { beforeEach(() => { - // eslint-disable-next-line @typescript-eslint/no-empty-function - jest.spyOn(console, 'log').mockImplementation(() => { }); + jest.spyOn(console, 'log').mockImplementation(() => ({})); }); - test('when used as decorator, it returns a function with the correct scope of the decorated class', async () => { + test('it returns a decorated method with the correct scope of the decorated class', async () => { // Prepare @@ -875,7 +881,7 @@ describe('Class: Logger', () => { @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { this.myClassMethod(); } @@ -884,9 +890,11 @@ describe('Class: Logger', () => { } } + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); // Act - await new LambdaFunction().handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(1); @@ -905,7 +913,7 @@ describe('Class: Logger', () => { }); - test('when used as decorator, it returns a function that captures Lambda\'s context information and adds it in the printed logs', async () => { + test('it captures Lambda\'s context information and adds it in the printed logs', async () => { // Prepare const logger = new Logger(); @@ -915,14 +923,16 @@ describe('Class: Logger', () => { @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { logger.info('This is an INFO log with some context'); } } + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); // Act logger.info('An INFO log without context!'); - await new LambdaFunction().handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess @@ -949,7 +959,7 @@ describe('Class: Logger', () => { }); - test('when used as decorator on an async handler without context, it returns a function that captures Lambda\'s context information and adds it in the printed logs', async () => { + test('it captures Lambda\'s context information and adds it in the printed logs for async methods', async () => { // Prepare const expectedReturnValue = 'Lambda invoked!'; @@ -966,10 +976,12 @@ describe('Class: Logger', () => { return expectedReturnValue; } } + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); // Act logger.info('An INFO log without context!'); - const actualResult = await new LambdaFunction().handler(event, context); + const actualResult = await handler(event, context); // Assess @@ -997,7 +1009,7 @@ describe('Class: Logger', () => { }); - test('when used as decorator with the clear state flag enabled, the persistent log attributes added in the handler are removed after the handler\'s code is executed', async () => { + test('when clearState is enabled, the persistent log attributes added in the handler are cleared when the method returns', async () => { // Prepare const logger = new Logger({ @@ -1007,40 +1019,38 @@ describe('Class: Logger', () => { biz: 'baz' } }); - - type CustomEvent = { user_id: string }; - class LambdaFunction implements LambdaInterface { @logger.injectLambdaContext({ clearState: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public handler(event: CustomEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: event['user_id'] } + details: { user_id: '1234' } }); logger.debug('This is a DEBUG log with the user_id'); logger.debug('This is another DEBUG log with the user_id'); } } - - const persistentAttribs = { ...logger.getPersistentLogAttributes() }; + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); + const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; // Act - await new LambdaFunction().handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); + await handler(event, context); const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; // Assess - expect(persistentAttribs).toEqual({ + expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', biz: 'baz' }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs); + expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); }); - test('when used as decorator with the clear state flag enabled and the handler throws an error, the persistent log attributes added in the handler are removed after the handler\'s code is executed', async () => { + test('when clearState is enabled, the persistent log attributes added in the handler are cleared when the method throws', async () => { // Prepare const logger = new Logger({ @@ -1050,18 +1060,15 @@ describe('Class: Logger', () => { biz: 'baz' } }); - - type CustomEvent = { user_id: string }; - class LambdaFunction implements LambdaInterface { @logger.injectLambdaContext({ clearState: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public handler(event: CustomEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: event['user_id'] } + details: { user_id: '1234' } }); logger.debug('This is a DEBUG log with the user_id'); logger.debug('This is another DEBUG log with the user_id'); @@ -1069,45 +1076,42 @@ describe('Class: Logger', () => { throw new Error('Unexpected error occurred!'); } } - - const persistentAttribs = { ...logger.getPersistentLogAttributes() }; + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); + const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; // Act & Assess - const executeLambdaHandler = async (): Promise => { - await new LambdaFunction().handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); - }; - await expect(executeLambdaHandler()).rejects.toThrow('Unexpected error occurred!'); + await expect(handler(event, context)).rejects.toThrow(); const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; - expect(persistentAttribs).toEqual({ + expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', biz: 'baz' }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs); + expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); }); - test('when used as decorator with the log event flag enabled, it logs the event', async () => { + test('when logEvent is enabled, it logs the event in the first log', 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(_event: CustomEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { return; } } + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); // Act - await new LambdaFunction().handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(1); @@ -1123,13 +1127,15 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { - user_id: '123456' + key1: 'value1', + key2: 'value2', + key3: 'value3' } })); }); - test('when used as decorator without options, but POWERTOOLS_LOGGER_LOG_EVENT env var is set to true, it logs the event', async () => { + test('when logEvent is enabled via POWERTOOLS_LOGGER_LOG_EVENT env var, it logs the event', async () => { // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true'; @@ -1138,20 +1144,20 @@ describe('Class: Logger', () => { }); 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(_event: CustomEvent, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { return; } } + const handlerClass = new LambdaFunction(); + const handler = handlerClass.handler.bind(handlerClass); // Act - await new LambdaFunction().handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(1); @@ -1167,13 +1173,15 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { - user_id: '123456' + key1: 'value1', + key2: 'value2', + key3: 'value3' } })); }); - test('when used as decorator the value of `this` is preserved on the decorated method/class', async () => { + test('it preserves the value of `this` of the decorated method/class', async () => { // Prepare const logger = new Logger({ @@ -1191,7 +1199,7 @@ describe('Class: Logger', () => { @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public handler(_event: unknown, _context: Context, _callback: Callback): void | Promise { + public async handler(_event: TEvent, _context: Context): Promise { this.dummyMethod(); return; @@ -1201,11 +1209,11 @@ describe('Class: Logger', () => { logger.info({ message: `memberVariable:${this.memberVariable}` }); } } - - // Act const lambda = new LambdaFunction('someValue'); const handler = lambda.handler.bind(lambda); - await handler({}, context, () => console.log('Lambda invoked!')); + + // Act + await handler({}, context); // Assess expect(consoleSpy).toBeCalledTimes(1); @@ -1224,7 +1232,7 @@ describe('Class: Logger', () => { }); - test('when used as decorator on an async method, the method is awaited correctly', async () => { + test('it awaits the decorated method correctly', async () => { // Prepare const injectLambdaContextAfterOrOnErrorMock = jest.fn().mockReturnValue('worked'); @@ -1270,7 +1278,7 @@ describe('Class: Logger', () => { describe('Method: refreshSampleRateCalculation', () => { - test('when called, it recalculates whether the current Lambda invocation\'s logs will be printed or not', () => { + test('it recalculates whether the current Lambda invocation\'s logs will be printed or not', () => { // Prepare const logger = new Logger({ @@ -1302,7 +1310,7 @@ describe('Class: Logger', () => { const INDENTATION = LogJsonIndent.COMPACT; const loggerOptions = { serviceName: 'parent-service-name', - sampleRateValue: 0.01, + sampleRateValue: 0, }; const parentLogger = new Logger(loggerOptions); @@ -1339,7 +1347,7 @@ describe('Class: Logger', () => { powertoolLogData: { awsRegion: 'eu-west-1', environment: '', - sampleRateValue: 0.01, + sampleRateValue: undefined, serviceName: 'parent-service-name', }, }); @@ -1655,22 +1663,8 @@ describe('Class: Logger', () => { serviceName: 'hello-world', }, }); - }); - const context = { - callbackWaitsForEmptyEventLoop: true, - functionVersion: '$LATEST', - functionName: 'foo-bar-function-with-cold-start', - memoryLimitInMB: '128', - logGroupName: '/aws/lambda/foo-bar-function-with-cold-start', - logStreamName: '2021/03/09/[$LATEST]1-5759e988-bd862e3fe1be46a994272793', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function-with-cold-start', - awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - getRemainingTimeInMillis: () => 1234, - done: () => console.log('Done!'), - fail: () => console.log('Failed!'), - succeed: () => console.log('Succeeded!'), - }; + }); test('child logger should have parent\'s context in PowertoolLogData', () => { @@ -1706,15 +1700,16 @@ describe('Class: Logger', () => { lambdaContext: { awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', coldStart: true, - functionName: 'foo-bar-function-with-cold-start', + functionName: 'foo-bar-function', functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function-with-cold-start', + invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', memoryLimitInMB: 128, }, sampleRateValue: undefined, serviceName: 'hello-world', }, }); + }); test('child logger should have parent\'s logFormatter', () => { @@ -1734,6 +1729,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(MyCustomLogFormatter), }) ); + }); test('child logger with custom logFormatter in options should have provided logFormatter', () => { @@ -1759,6 +1755,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(MyCustomLogFormatter), }) ); + }); test('child logger should have exact same attributes as the parent logger created with all non-default options', () => { @@ -1819,8 +1816,8 @@ describe('Class: Logger', () => { logger.logEventIfEnabled(event); // Assess - expect(consoleSpy).toBeCalledTimes(0); + }); test('When the feature is enabled via overwrite flag, it DOES log the event', () => { @@ -1848,6 +1845,7 @@ describe('Class: Logger', () => { } }, )); + }); }); @@ -1873,6 +1871,7 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', }, null, INDENTATION)); + }); test('when the `POWERTOOLS_DEV` env var is NOT SET it makes log output as one-liner', () => { @@ -1893,7 +1892,9 @@ describe('Class: Logger', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', })); + }); + }); describe('Method: setConsole()', () => { @@ -1916,7 +1917,9 @@ describe('Class: Logger', () => { ...logger, console: console, }); + }); + }); }); diff --git a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts index b9aa387614..637c9ca615 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -3,7 +3,6 @@ * * @group unit/logger/all */ - import { EnvironmentVariablesService } from '../../../src/config'; describe('Class: EnvironmentVariablesService', () => { @@ -21,7 +20,7 @@ describe('Class: EnvironmentVariablesService', () => { describe('Method: getAwsRegion', () => { - test('It returns the value of the environment variable AWS_REGION', () => { + test('it returns the value of the environment variable AWS_REGION', () => { // Prepare process.env.AWS_REGION = 'us-east-1'; @@ -32,13 +31,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('us-east-1'); + }); }); describe('Method: getCurrentEnvironment', () => { - test('It returns the value of the environment variable AWS_REGION', () => { + test('it returns the value of the environment variable AWS_REGION', () => { // Prepare process.env.ENVIRONMENT = 'stage'; @@ -55,7 +55,7 @@ describe('Class: EnvironmentVariablesService', () => { describe('Method: getFunctionMemory', () => { - test('It returns the value of the environment variable AWS_LAMBDA_FUNCTION_MEMORY_SIZE', () => { + test('it returns the value of the environment variable AWS_LAMBDA_FUNCTION_MEMORY_SIZE', () => { // Prepare process.env.AWS_LAMBDA_FUNCTION_MEMORY_SIZE = '123456'; @@ -66,13 +66,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toBe(123456); + }); }); describe('Method: getFunctionName', () => { - test('It returns the value of the environment variable AWS_LAMBDA_FUNCTION_NAME', () => { + test('it returns the value of the environment variable AWS_LAMBDA_FUNCTION_NAME', () => { // Prepare process.env.AWS_LAMBDA_FUNCTION_NAME = 'my-lambda-function'; @@ -83,13 +84,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('my-lambda-function'); + }); }); describe('Method: getFunctionVersion', () => { - test('It returns the value of the environment variable AWS_LAMBDA_FUNCTION_VERSION', () => { + test('it returns the value of the environment variable AWS_LAMBDA_FUNCTION_VERSION', () => { // Prepare process.env.AWS_LAMBDA_FUNCTION_VERSION = '1.4.0'; @@ -100,13 +102,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('1.4.0'); + }); }); describe('Method: getLogEvent', () => { - test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "true"', () => { + test('it returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "true"', () => { // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true'; @@ -117,9 +120,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(true); + }); - test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "false"', () => { + test('it returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "false"', () => { // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'false'; @@ -130,9 +134,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); + }); - test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "somethingsilly"', () => { + test('it returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "somethingsilly"', () => { // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'somethingsilly'; @@ -143,13 +148,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); + }); }); describe('Method: getLogLevel', () => { - test('It returns the value of the environment variable LOG_LEVEL', () => { + test('it returns the value of the environment variable LOG_LEVEL', () => { // Prepare process.env.LOG_LEVEL = 'ERROR'; @@ -160,13 +166,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('ERROR'); + }); }); describe('Method: getSampleRateValue', () => { - test('It returns the value of the environment variable POWERTOOLS_LOGGER_SAMPLE_RATE', () => { + test('it returns the value of the environment variable POWERTOOLS_LOGGER_SAMPLE_RATE', () => { // Prepare process.env.POWERTOOLS_LOGGER_SAMPLE_RATE = '0.01'; @@ -177,13 +184,14 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(0.01); + }); }); describe('Method: isDevMode', () => { - test('It returns true if the environment variable POWERTOOLS_DEV is "true"', () => { + test('it returns true if the environment variable POWERTOOLS_DEV is "true"', () => { // Prepare process.env.POWERTOOLS_DEV = 'true'; @@ -194,9 +202,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(true); + }); - test('It returns false if the environment variable POWERTOOLS_DEV is "false"', () => { + test('it returns false if the environment variable POWERTOOLS_DEV is "false"', () => { // Prepare process.env.POWERTOOLS_DEV = 'false'; @@ -207,9 +216,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); + }); - test('It returns false if the environment variable POWERTOOLS_DEV is NOT set', () => { + test('it returns false if the environment variable POWERTOOLS_DEV is NOT set', () => { // Prepare process.env.POWERTOOLS_DEV = 'somethingsilly'; @@ -220,9 +230,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); + }); - test('It returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => { + test('it returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => { // Prepare process.env.POWERTOOLS_DEV = 'somethingsilly'; @@ -233,6 +244,7 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); + }); }); @@ -253,7 +265,7 @@ describe('Class: EnvironmentVariablesService', () => { [ '0', false ] ]; - test.each(valuesToTest)('It takes string "%s" and returns %s', (input, output) => { + test.each(valuesToTest)('it takes string "%s" and returns %s', (input, output) => { // Prepare const service = new EnvironmentVariablesService(); // Act diff --git a/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts b/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts index 8b7f52a82e..4d8d4100f5 100644 --- a/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts +++ b/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts @@ -3,7 +3,6 @@ * * @group unit/logger/all */ - import { AssertionError, strictEqual } from 'assert'; import { PowertoolLogFormatter } from '../../../src/formatter'; import { UnformattedAttributes } from '../../../src/types'; @@ -19,7 +18,7 @@ describe('Class: PowertoolLogFormatter', () => { describe('Method: formatAttributes', () => { - test('When optional parameters DO NOT have a value set, it returns an object with expected structure and values', () => { + test('when optional parameters DO NOT have a value set, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -51,9 +50,10 @@ describe('Class: PowertoolLogFormatter', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', }); + }); - test('When optional parameters DO have a value set, it returns an object with expected structure and values', () => { + test('when optional parameters DO have a value set, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -94,19 +94,18 @@ describe('Class: PowertoolLogFormatter', () => { timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', }); + }); }); describe('Method: formatError', () => { - test('When an error of type Error is passed, it returns an object with expected structure and values', () => { + test('when an error of type Error is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-ignore throw new Error('Ouch!'); }; @@ -126,13 +125,15 @@ describe('Class: PowertoolLogFormatter', () => { } expect(shouldThrow).toThrowError(expect.any(Error)); + }); - test('When an error of type ReferenceError is passed, it returns an object with expected structure and values', () => { + test('when an error of type ReferenceError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { + // This is a reference error purposely to test the formatter // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore doesNotExist; @@ -157,13 +158,11 @@ describe('Class: PowertoolLogFormatter', () => { }); - test('When an error of type AssertionError is passed, it returns an object with expected structure and values', () => { + test('when an error of type AssertionError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-ignore strictEqual(1, 2); }; @@ -186,13 +185,11 @@ describe('Class: PowertoolLogFormatter', () => { }); - test('When an error of type RangeError is passed, it returns an object with expected structure and values', () => { + test('when an error of type RangeError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-ignore throw new RangeError('The argument must be between 10 and 20'); }; @@ -214,13 +211,11 @@ describe('Class: PowertoolLogFormatter', () => { expect(shouldThrow).toThrowError(expect.any(RangeError)); }); - test('When an error of type SyntaxError is passed, it returns an object with expected structure and values', () => { + test('when an error of type SyntaxError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-ignore eval('foo bar'); }; @@ -243,11 +238,12 @@ describe('Class: PowertoolLogFormatter', () => { }); - test('When an error of type TypeError is passed, it returns an object with expected structure and values', () => { + test('when an error of type TypeError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { + // This is a reference error purposely to test the formatter // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore null.foo(); @@ -270,15 +266,14 @@ describe('Class: PowertoolLogFormatter', () => { } expect(shouldThrow).toThrowError(expect.any(TypeError)); + }); - test('When an error of type URIError is passed, it returns an object with expected structure and values', () => { + test('when an error of type URIError is passed, it returns an object with expected structure and values', () => { // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-ignore decodeURIComponent('%'); }; @@ -298,13 +293,14 @@ describe('Class: PowertoolLogFormatter', () => { } expect(shouldThrow).toThrowError(expect.any(URIError)); + }); }); describe('Method: formatTimestamp', () => { - test('It returns a datetime value ISO 8601 compliant', () => { + test('it returns a datetime value ISO 8601 compliant', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -314,13 +310,14 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(timestamp).toEqual('2016-06-20T12:08:10.000Z'); + }); }); describe('Method: getCodeLocation', () => { - test('When the stack IS present, it returns a datetime value ISO 8601 compliant', () => { + test('when the stack IS present, it returns a datetime value ISO 8601 compliant', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -333,9 +330,10 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(errorLocation).toEqual('/home/foo/bar/some-file.ts:154'); + }); - test('When the stack IS NOT present, it returns a datetime value ISO 8601 compliant', () => { + test('when the stack IS NOT present, it returns a datetime value ISO 8601 compliant', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -346,9 +344,10 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(errorLocation).toEqual(''); + }); - test('When the stack IS NOT present, it returns a datetime value ISO 8601 compliant', () => { + test('when the stack IS NOT present, it returns a datetime value ISO 8601 compliant', () => { // Prepare const formatter = new PowertoolLogFormatter(); @@ -359,6 +358,7 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(errorLocation).toEqual(''); + }); }); diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index 4f953620fc..7235dec4ab 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -3,7 +3,6 @@ * * @group unit/logger/all */ - import { Console } from 'console'; import { ConfigServiceInterface, EnvironmentVariablesService } from '../../src/config'; import { LogFormatter, PowertoolLogFormatter } from '../../src/formatter'; @@ -197,6 +196,7 @@ describe('Helper: createLogger function', () => { logLevel: 'DEBUG', logFormatter: {}, })); + }); test('when a custom logLevel is passed, returns a Logger instance with the correct properties', () => { @@ -225,6 +225,7 @@ describe('Helper: createLogger function', () => { logLevel: 'ERROR', logFormatter: expect.any(PowertoolLogFormatter), })); + }); test('when no log level is set, returns a Logger instance with INFO level', () => { @@ -263,6 +264,7 @@ describe('Helper: createLogger function', () => { serviceName: 'hello-world', }, }); + }); test('when a custom sampleRateValue is passed, returns a Logger instance with the correct properties', () => { @@ -291,6 +293,7 @@ describe('Helper: createLogger function', () => { logLevel: 'DEBUG', logFormatter: {}, })); + }); test('when a custom customConfigService is passed, returns a Logger instance with the correct properties', () => { @@ -346,6 +349,7 @@ describe('Helper: createLogger function', () => { logLevel: 'INFO', logFormatter: {}, })); + }); test('when custom persistentLogAttributes is passed, returns a Logger instance with the correct properties', () => { @@ -388,6 +392,7 @@ describe('Helper: createLogger function', () => { logLevel: 'DEBUG', logFormatter: {}, })); + }); test('when a custom environment is passed, returns a Logger instance with the correct properties', () => { @@ -416,7 +421,9 @@ describe('Helper: createLogger function', () => { logLevel: 'DEBUG', logFormatter: {}, })); + }); + }); }); \ No newline at end of file diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index fff1960b1b..ed4abdb262 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -4,6 +4,7 @@ * @group unit/logger/all */ +import { ContextExamples as dummyContext, Events as dummyEvent } from '@aws-lambda-powertools/commons'; import { ConfigServiceInterface, EnvironmentVariablesService } from '../../../src/config'; import { injectLambdaContext } from '../../../src/middleware/middy'; import { Logger } from './../../../src'; @@ -17,6 +18,8 @@ const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); describe('Middy middleware', () => { const ENVIRONMENT_VARIABLES = process.env; + const context = dummyContext.helloworldContext; + const event = dummyEvent.Custom.CustomEvent; beforeEach(() => { jest.resetModules(); @@ -37,31 +40,12 @@ describe('Middy middleware', () => { // Prepare const logger = new Logger(); - const lambdaHandler = (): void => { + const handler = middy((): 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', - 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!'), - }; + }).use(injectLambdaContext(logger)); // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(logger).toEqual(expect.objectContaining({ @@ -72,7 +56,7 @@ describe('Middy middleware', () => { awsRegion: 'eu-west-1', environment: '', lambdaContext: { - awsRequestId: awsRequestId, + awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', coldStart: true, functionName: 'foo-bar-function', functionVersion: '$LATEST', @@ -94,34 +78,13 @@ describe('Middy middleware', () => { // Prepare const logger = new Logger(); const anotherLogger = new Logger(); - const lambdaHandler = (): void => { + const handler = middy((): void => { logger.info('This is an INFO log with some context'); anotherLogger.info('This is an INFO log with some context'); - }; - const handler = middy(lambdaHandler).use(injectLambdaContext([ logger, anotherLogger ])); - 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!'), - }; + }).use(injectLambdaContext([ logger, anotherLogger ])); // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess const expectation = expect.objectContaining({ @@ -132,7 +95,7 @@ describe('Middy middleware', () => { awsRegion: 'eu-west-1', environment: '', lambdaContext: { - awsRequestId: awsRequestId, + awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', coldStart: true, functionName: 'foo-bar-function', functionVersion: '$LATEST', @@ -168,46 +131,31 @@ describe('Middy middleware', () => { 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 => { + const handler = middy((): void => { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: event['user_id'] } + details: { user_id: '1234' } }); 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() }; - + }).use(injectLambdaContext(logger, { clearState: true })); + const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; + // Act - await handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); - const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; - + await handler(event, context); + // Assess - expect(persistentAttribs).toEqual({ + const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; + expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', biz: 'baz' }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs); + expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); }); - test('when enabled and the handler throws an error, the persistent log attributes added within the handler scope are removed after the invocation ends', async () => { + test('when enabled, the persistent log attributes added within the handler scope are removed after the invocation ends even if an error is thrown', async () => { // Prepare const logger = new Logger({ @@ -217,46 +165,27 @@ describe('Middy middleware', () => { 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 => { + const handler = middy((): void => { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: event['user_id'] } + details: { user_id: '1234' } }); logger.debug('This is a DEBUG log with the user_id'); logger.debug('This is another DEBUG log with the user_id'); throw new Error('Unexpected error occurred!'); - }; - - const persistentAttribs = { ...logger.getPersistentLogAttributes() }; - const handler = middy(lambdaHandler).use(injectLambdaContext(logger, { clearState: true })); - + }).use(injectLambdaContext(logger, { clearState: true })); + const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; + // Act & Assess - const executeLambdaHandler = async (): Promise => { - await handler({ user_id: '123456' }, context, () => console.log('Lambda invoked!')); - }; - await expect(executeLambdaHandler()).rejects.toThrow('Unexpected error occurred!'); + await expect(handler(event, context)) + .rejects.toThrow(); const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; - expect(persistentAttribs).toEqual({ + expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', biz: 'baz' }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs); + expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); }); @@ -264,35 +193,17 @@ describe('Middy middleware', () => { describe('Feature: log event', () => { - test('when a logger is passed with option logEvent set to true, it logs the event', async () => { + test('when enabled, it logs the event', async () => { // Prepare const logger = new Logger(); const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); - const lambdaHandler = (): void => { + const handler = middy((): void => { logger.info('This is an INFO log with some context'); - }; - const handler = middy(lambdaHandler).use(injectLambdaContext(logger , { logEvent: true })); - 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!'), - }; + }).use(injectLambdaContext(logger , { logEvent: true })); // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); @@ -301,20 +212,22 @@ describe('Middy middleware', () => { 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, + 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: { - foo: 'bar' + key1: 'value1', + key2: 'value2', + key3: 'value3', } })); }); - test('when a logger is passed with option logEvent set to true, while also having a custom configService, it logs the event', async () => { + test('when enabled, while also having a custom configService, it logs the event', async () => { // Prepare const configService: ConfigServiceInterface = { @@ -348,30 +261,12 @@ describe('Middy middleware', () => { customConfigService: configService, }); const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); - const lambdaHandler = (): void => { + const handler = middy((): void => { logger.info('This is an INFO log with some context'); - }; - const handler = middy(lambdaHandler).use(injectLambdaContext(logger , { logEvent: true })); - 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!'), - }; - + }).use(injectLambdaContext(logger , { logEvent: true })); + // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); @@ -380,49 +275,33 @@ describe('Middy middleware', () => { 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, + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', level: 'INFO', message: 'Lambda invocation event', service: 'my-backend-service', timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { - foo: 'bar' + key1: 'value1', + key2: 'value2', + key3: 'value3', } })); }); - test('when a logger is passed without options, but POWERTOOLS_LOGGER_LOG_EVENT env var is set to true, it logs the event', async () => { + test('when enabled via POWERTOOLS_LOGGER_LOG_EVENT env var, it logs 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 => { + const handler = middy((): 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', - 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!'), - }; - + }).use(injectLambdaContext(logger)); + // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); @@ -431,49 +310,33 @@ describe('Middy middleware', () => { 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, + 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: { - foo: 'bar' + key1: 'value1', + key2: 'value2', + key3: 'value3', } })); }); - 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 () => { + test('when disabled in the middleware, but enabled via POWERTOOLS_LOGGER_LOG_EVENT env var, it still doesn\'t 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 => { + const handler = middy((): void => { logger.info('This is an INFO log'); - }; - 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!'), - }; - + }).use(injectLambdaContext(logger, { logEvent: false })); + // Act - await handler(event, context, () => console.log('Lambda invoked!')); + await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(1); @@ -482,7 +345,7 @@ describe('Middy middleware', () => { 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, + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', level: 'INFO', message: 'This is an INFO log', service: 'hello-world',