From bcfce3d913bdd264d12d59b6af6eadc22eb19315 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Wed, 2 Mar 2022 09:08:59 +0100 Subject: [PATCH 01/10] feat(logger): log event, add business logic and unit tests --- packages/logger/src/Logger.ts | 55 +++++++++++++++++++++- packages/logger/src/middleware/middy.ts | 4 +- packages/logger/src/types/Logger.ts | 5 ++ packages/logger/tests/unit/Logger.test.ts | 52 ++++++++++++++++++-- packages/logger/tests/unit/helpers.test.ts | 3 ++ 5 files changed, 111 insertions(+), 8 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 47cadacfa5..7eebc07b85 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -7,7 +7,7 @@ import merge from 'lodash.merge'; import { ConfigServiceInterface, EnvironmentVariablesService } from './config'; import type { ClassThatLogs, - Environment, + Environment, ExtraOptions, HandlerMethodDecorator, LambdaFunctionContext, LogAttributes, @@ -115,6 +115,8 @@ class Logger extends Utility implements ClassThatLogs { private envVarsService?: EnvironmentVariablesService; + private logEvent: boolean = false; + private logFormatter?: LogFormatterInterface; private logLevel?: LogLevel; @@ -227,6 +229,16 @@ class Logger extends Utility implements ClassThatLogs { return this.logsSampled; } + /** + * It returns a boolean value. True means that the Lambda invocation events + * are printed in the logs. + * + * @returns {boolean} + */ + public getLogEvent(): boolean { + return this.logEvent; + } + /** * It prints a log item with level INFO. * @@ -238,6 +250,20 @@ class Logger extends Utility implements ClassThatLogs { this.processLogItem('INFO', input, extraInput); } + /** + * Logs a Lambda invocation event, if it *should*. + * + ** @param {unknown} event + * @param {boolean} [overwriteValue] + * @returns {void} + */ + public logEventIfEnabled(event: unknown, overwriteValue?: boolean): void { + if(!this.shouldLogEvent(overwriteValue)) { + return; + } + this.info('Lambda invocation event', { event: event }) + } + /** * Method decorator that adds the current Lambda function context as extra * information in all log items. @@ -247,11 +273,12 @@ class Logger extends Utility implements ClassThatLogs { * @see https://www.typescriptlang.org/docs/handbook/decorators.html#method-decorators * @returns {HandlerMethodDecorator} */ - public injectLambdaContext(): HandlerMethodDecorator { + public injectLambdaContext(options: ExtraOptions = {}): HandlerMethodDecorator { return (target, _propertyKey, descriptor) => { const originalMethod = descriptor.value; descriptor.value = (event, context, callback) => { + this.logEventIfEnabled(event, options.logEvent); this.addContext(context); return originalMethod?.apply(target, [ event, context, callback ]); @@ -271,6 +298,15 @@ class Logger extends Utility implements ClassThatLogs { this.setLogsSampled(); } + /** + * If set to true, the Lambda function invocation events are printed in the logs. + * + * @returns {void} + */ + public setLogEvent(value: boolean): void { + this.logEvent = value; + } + /** * It sets the user-provided sample rate value. * @@ -284,6 +320,21 @@ class Logger extends Utility implements ClassThatLogs { this.getEnvVarsService().getSampleRateValue(); } + /** + * It checks whether the current Lambda invocation event should be printed in the logs or not. + * + * @private + * @param {boolean} [overwriteValue] + * @returns {boolean} + */ + public shouldLogEvent(overwriteValue?: boolean): boolean { + if (typeof overwriteValue === 'boolean') { + return overwriteValue; + } + + return this.getLogEvent(); + } + /** * It prints a log item with level WARN. * diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index cdb53183e2..8225f0cc03 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -1,5 +1,6 @@ import type { Logger } from '../Logger'; import type middy from '@middy/core'; +import { ExtraOptions } from '../types'; /** * A middy middleware that adds the current Lambda invocation's context inside all log items. @@ -26,10 +27,11 @@ import type middy from '@middy/core'; * @param {Logger|Logger[]} target - The Tracer instance to use for tracing * @returns {middy.MiddlewareObj} - The middy middleware object */ -const injectLambdaContext = (target: Logger | Logger[]): middy.MiddlewareObj => { +const injectLambdaContext = (target: Logger | Logger[], options: ExtraOptions = {}): middy.MiddlewareObj => { const injectLambdaContextBefore = async (request: middy.Request): Promise => { const loggers = target instanceof Array ? target : [target]; loggers.forEach((logger: Logger) => { + logger.logEventIfEnabled(request.event, options.logEvent); logger.addContext(request.context); }); }; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 770dfb1244..019820f5ac 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -8,6 +8,10 @@ type ClassThatLogs = { [key in 'debug' | 'error' | 'info' | 'warn']: (input: LogItemMessage, ...extraInput: LogItemExtraInput) => void; }; +type ExtraOptions = { + logEvent?: boolean +}; + type LoggerOptions = { logLevel?: LogLevel serviceName?: string @@ -60,6 +64,7 @@ type HandlerMethodDecorator = ( export { ClassThatLogs, + ExtraOptions, LogItemMessage, LogItemExtraInput, HandlerMethodDecorator, diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index ba295c064e..1d67f6876d 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -465,6 +465,7 @@ describe('Class: Logger', () => { coldStart: false, // This is now false because the `coldStart` attribute has been already accessed once by the `addContext` method customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -603,11 +604,6 @@ describe('Class: Logger', () => { describe('Method: injectLambdaContext', () => { - beforeEach(() => { - // eslint-disable-next-line @typescript-eslint/no-empty-function - jest.spyOn(console, 'log').mockImplementation(() => {}); - }); - test('when used as decorator, it returns a function with the correct scope of the decorated class', async () => { // Prepare @@ -739,6 +735,8 @@ describe('Class: Logger', () => { }); + + describe('Method: refreshSampleRateCalculation', () => { test('when called, it recalculates whether the current Lambda invocation\'s logs will be printed or not', () => { @@ -798,6 +796,7 @@ describe('Class: Logger', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -821,6 +820,7 @@ describe('Class: Logger', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -846,6 +846,7 @@ describe('Class: Logger', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -869,6 +870,7 @@ describe('Class: Logger', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'ERROR', logLevelThresholds: { @@ -892,4 +894,44 @@ describe('Class: Logger', () => { }); + describe('Method: logEventIfEnabled', () => { + + test('When the feature is disabled, it DOES NOT log the event', () => { + + // Prepare + const logger = new Logger(); + + // Act + logger.logEventIfEnabled(dummyEvent); + + // Assess + expect(console['info']).toBeCalledTimes(0); + }); + + test.only('When the feature is enabled via overwrite flag, it DOES log the event', () => { + + // Prepare + const logger = new Logger(); + + // Act + logger.logEventIfEnabled(dummyEvent, true); + + // Assess + expect(console['info']).toBeCalledTimes(1); + expect(console['info']).toHaveBeenNthCalledWith(1, JSON.stringify({ + level: 'INFO', + message: 'An INFO log without context!', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: 'abcdef123456abcdef123456abcdef123456', + event: { + key1: "value1", + key2: "value2", + key3: "value3" + } + }, + )); + }); + }); + }); \ No newline at end of file diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index 9d3525d343..61102d04a8 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -76,6 +76,7 @@ describe('Helper: createLogger function', () => { coldStart: true, customConfigService: expect.any(EnvironmentVariablesService), envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'WARN', logLevelThresholds: { @@ -115,6 +116,7 @@ describe('Helper: createLogger function', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'INFO', logLevelThresholds: { @@ -238,6 +240,7 @@ describe('Helper: createLogger function', () => { coldStart: true, customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), + logEvent: false, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'INFO', logLevelThresholds: { From 72a4466d6c46f0e214345869965d94645ad4f219 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 3 Mar 2022 11:53:54 +0100 Subject: [PATCH 02/10] test(logger): add log event support --- packages/logger/tests/unit/Logger.test.ts | 18 ++++++++++++------ packages/logger/tests/unit/helpers.test.ts | 3 +++ 2 files changed, 15 insertions(+), 6 deletions(-) diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index 1d67f6876d..ac240dcc7f 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -604,6 +604,11 @@ describe('Class: Logger', () => { describe('Method: injectLambdaContext', () => { + beforeEach(() => { + // eslint-disable-next-line @typescript-eslint/no-empty-function + jest.spyOn(console, 'log').mockImplementation(() => {}); + }); + test('when used as decorator, it returns a function with the correct scope of the decorated class', async () => { // Prepare @@ -908,26 +913,27 @@ describe('Class: Logger', () => { expect(console['info']).toBeCalledTimes(0); }); - test.only('When the feature is enabled via overwrite flag, it DOES log the event', () => { + test('When the feature is enabled via overwrite flag, it DOES log the event', () => { // Prepare + const event = { + something: 'happened!' + }; const logger = new Logger(); // Act - logger.logEventIfEnabled(dummyEvent, true); + logger.logEventIfEnabled(event, true); // Assess expect(console['info']).toBeCalledTimes(1); expect(console['info']).toHaveBeenNthCalledWith(1, JSON.stringify({ level: 'INFO', - message: 'An INFO log without context!', + message: 'Lambda invocation event', service: 'hello-world', timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: 'abcdef123456abcdef123456abcdef123456', event: { - key1: "value1", - key2: "value2", - key3: "value3" + something: "happened!" } }, )); diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index 61102d04a8..c35f42ecac 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -299,6 +299,9 @@ describe('Helper: createLogger function', () => { getCurrentEnvironment(): string { return 'dev'; }, + getLogEvent(): boolean { + return false; + }, getLogLevel(): string { return 'INFO'; }, From 4a6e54139822b0930aaac469d34c78f13521d390 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 3 Mar 2022 11:54:23 +0100 Subject: [PATCH 03/10] feat(logger): add env variable for log event --- packages/logger/src/Logger.ts | 9 +++++---- packages/logger/src/config/ConfigService.ts | 20 +++++++++++++++++++ .../src/config/ConfigServiceInterface.ts | 7 +++++++ .../src/config/EnvironmentVariablesService.ts | 9 +++++++++ 4 files changed, 41 insertions(+), 4 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 7eebc07b85..a5ac99abdb 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -261,7 +261,7 @@ class Logger extends Utility implements ClassThatLogs { if(!this.shouldLogEvent(overwriteValue)) { return; } - this.info('Lambda invocation event', { event: event }) + this.info('Lambda invocation event', { event }) } /** @@ -299,12 +299,13 @@ class Logger extends Utility implements ClassThatLogs { } /** - * If set to true, the Lambda function invocation events are printed in the logs. + * It sets the log event flag value. * + * @param {number} [sampleRateValue] * @returns {void} */ - public setLogEvent(value: boolean): void { - this.logEvent = value; + public setLogEvent(): void { + this.logEvent = this.getCustomConfigService()?.getLogEvent() || this.getEnvVarsService().getLogEvent(); } /** diff --git a/packages/logger/src/config/ConfigService.ts b/packages/logger/src/config/ConfigService.ts index 4f38cf6ae6..06e7195ea3 100644 --- a/packages/logger/src/config/ConfigService.ts +++ b/packages/logger/src/config/ConfigService.ts @@ -22,6 +22,7 @@ abstract class ConfigService implements ConfigServiceInterface { protected logLevelVariable = 'LOG_LEVEL'; protected sampleRateValueVariable = 'POWERTOOLS_LOGGER_SAMPLE_RATE'; protected serviceNameVariable = 'POWERTOOLS_SERVICE_NAME'; + protected logEventVariable = 'POWERTOOLS_LOGGER_LOG_EVENT'; /** * It returns the value of an environment variable that has given name. @@ -38,6 +39,13 @@ abstract class ConfigService implements ConfigServiceInterface { */ public abstract getCurrentEnvironment(): string; + /** + * It returns the value of the POWERTOOLS_LOGGER_LOG_EVENT environment variable. + * + * @returns {boolean} + */ + public abstract getLogEvent(): boolean; + /** * It returns the value of the LOG_LEVEL environment variable. * @@ -59,6 +67,18 @@ abstract class ConfigService implements ConfigServiceInterface { */ public abstract getServiceName(): string; + /** + * It returns true if the string value represents a boolean true value. + * + * @param {string} value + * @returns boolean + * @protected + */ + protected isValueTrue(value: string): boolean { + const normalizedValue = value.toLowerCase(); + return normalizedValue === 'true' || normalizedValue === '1'; + } + } export { diff --git a/packages/logger/src/config/ConfigServiceInterface.ts b/packages/logger/src/config/ConfigServiceInterface.ts index 0e9b62a409..1f1a6ecc32 100644 --- a/packages/logger/src/config/ConfigServiceInterface.ts +++ b/packages/logger/src/config/ConfigServiceInterface.ts @@ -22,6 +22,13 @@ interface ConfigServiceInterface { */ getCurrentEnvironment(): string + /** + * It returns the value of the POWERTOOLS_LOGGER_LOG_EVENT environment variable. + * + * @returns {boolean} + */ + getLogEvent(): boolean + /** * It returns the value of the LOG_LEVEL environment variable. * diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index 588af64a01..2484252a65 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -79,6 +79,15 @@ class EnvironmentVariablesService extends ConfigService { return this.get(this.functionVersionVariable); } + /** + * It returns the value of the POWERTOOLS_LOGGER_LOG_EVENT environment variable. + * + * @returns {boolean} + */ + public getLogEvent(): boolean { + return this.isValueTrue(this.get(this.logEventVariable)); + } + /** * It returns the value of the LOG_LEVEL environment variable. * From 1a35b8ecbe08e01edd677e37632e57c36ca4be95 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Tue, 8 Mar 2022 10:13:06 +0100 Subject: [PATCH 04/10] test(logger): middy --- packages/logger/src/Logger.ts | 2 +- packages/logger/src/middleware/middy.ts | 2 +- .../tests/unit/middleware/middy.test.ts | 144 +++++++++++++++++- 3 files changed, 142 insertions(+), 6 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index a5ac99abdb..cc7feea429 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -278,8 +278,8 @@ class Logger extends Utility implements ClassThatLogs { const originalMethod = descriptor.value; descriptor.value = (event, context, callback) => { - this.logEventIfEnabled(event, options.logEvent); this.addContext(context); + this.logEventIfEnabled(event, options.logEvent); return originalMethod?.apply(target, [ event, context, callback ]); }; diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index 8225f0cc03..e4fbf1d9a7 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -31,8 +31,8 @@ const injectLambdaContext = (target: Logger | Logger[], options: ExtraOptions = const injectLambdaContextBefore = async (request: middy.Request): Promise => { const loggers = target instanceof Array ? target : [target]; loggers.forEach((logger: Logger) => { - logger.logEventIfEnabled(request.event, options.logEvent); logger.addContext(request.context); + logger.logEventIfEnabled(request.event, options.logEvent); }); }; diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index 1993bf288f..7d85264774 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -4,20 +4,28 @@ * @group unit/logger/all */ -import { EnvironmentVariablesService } from '../../../src/config'; +import { ConfigServiceInterface, EnvironmentVariablesService } from '../../../src/config'; import { injectLambdaContext } from '../../../src/middleware/middy'; import { Logger } from './../../../src'; import middy from '@middy/core'; import { PowertoolLogFormatter } from '../../../src/formatter'; +const mockDate = new Date(1466424490000); +const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate as unknown as string); + +const consoleSpy = { + 'info': jest.spyOn(console, 'info').mockImplementation(), + 'log': jest.spyOn(console, 'log').mockImplementation(), +}; + describe('Middy middleware', () => { const ENVIRONMENT_VARIABLES = process.env; beforeEach(() => { - jest.resetModules(); - // eslint-disable-next-line @typescript-eslint/no-empty-function - jest.spyOn(console, 'log').mockImplementation(() => {}); + consoleSpy['info'].mockClear(); + consoleSpy['log'].mockClear(); + dateSpy.mockClear(); process.env = { ...ENVIRONMENT_VARIABLES }; }); @@ -141,6 +149,134 @@ describe('Middy middleware', () => { }); + test('when a logger is passed with option logEvent set to true, it logs the event', async () => { + + // Prepare + const logger = new Logger(); + const lambdaHandler = (): 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!'), + }; + + // Act + await handler(event, context, () => console.log('Lambda invoked!')); + + // Assess + expect(consoleSpy['info']).toBeCalledTimes(2); + expect(consoleSpy['info']).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: 'abcdef123456abcdef123456abcdef123456', + event: { + foo: 'bar' + } + })); + + + + }); + + + test('when a logger is passed with option logEvent set to true, it logs the event', async () => { + + // Prepare + const configService: ConfigServiceInterface = { + get(name: string): string { + return `a-string-from-${name}`; + }, + getCurrentEnvironment(): string { + return 'dev'; + }, + getLogEvent(): boolean { + return true; + }, + getLogLevel(): string { + return 'INFO'; + }, + getSampleRateValue(): number | undefined { + return undefined; + }, + getServiceName(): string { + return 'my-backend-service'; + }, + + }; + // Prepare + + const logger = new Logger({ + customConfigService: configService, + }); + const lambdaHandler = (): 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!'), + }; + + // Act + await handler(event, context, () => console.log('Lambda invoked!')); + + // Assess + expect(consoleSpy['info']).toBeCalledTimes(2); + expect(consoleSpy['info']).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: 'abcdef123456abcdef123456abcdef123456', + event: { + foo: 'bar' + } + })); + + + + }); + }); }); \ No newline at end of file From a632918aef3befe0b161821d6c09e906e63203d1 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Wed, 22 Jun 2022 13:58:59 +0200 Subject: [PATCH 05/10] chore(logger): middy polish for log event --- packages/logger/src/middleware/middy.ts | 4 +- .../tests/unit/middleware/middy.test.ts | 128 +++++++++--------- 2 files changed, 67 insertions(+), 65 deletions(-) diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index 4dabfae059..34af3ac349 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -38,7 +38,9 @@ const injectLambdaContext = (target: Logger | Logger[], options?: HandlerOptions if (options && options.clearState === true) { persistentAttributes.push({ ...logger.getPersistentLogAttributes() }); } - logger.logEventIfEnabled(request.event, options.logEvent); + if (options) { + logger.logEventIfEnabled(request.event, options.logEvent); + } }); }; diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index 11056061ca..82f1ad9b72 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -11,12 +11,16 @@ import middy from '@middy/core'; import { PowertoolLogFormatter } from '../../../src/formatter'; import { Console } from 'console'; +const mockDate = new Date(1466424490000); +const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate as unknown as string); + describe('Middy middleware', () => { const ENVIRONMENT_VARIABLES = process.env; beforeEach(() => { jest.resetModules(); + dateSpy.mockClear(); jest.spyOn(process.stdout, 'write').mockImplementation(() => null as unknown as boolean); process.env = { ...ENVIRONMENT_VARIABLES }; }); @@ -87,15 +91,15 @@ describe('Middy middleware', () => { test('when a logger array is passed, it adds the context to all logger instances', async () => { - // Prepare - const logger = new Logger(); - const anotherLogger = new Logger(); - const lambdaHandler = (): 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' }; + // Prepare + const logger = new Logger(); + const anotherLogger = new Logger(); + const lambdaHandler = (): 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); @@ -153,6 +157,7 @@ describe('Middy middleware', () => { // Prepare 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'); }; @@ -179,8 +184,8 @@ describe('Middy middleware', () => { await handler(event, context, () => console.log('Lambda invoked!')); // Assess - expect(consoleSpy['info']).toBeCalledTimes(2); - expect(consoleSpy['info']).toHaveBeenNthCalledWith(1, JSON.stringify({ + 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, @@ -190,17 +195,14 @@ describe('Middy middleware', () => { message: 'Lambda invocation event', service: 'hello-world', timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: 'abcdef123456abcdef123456abcdef123456', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { foo: 'bar' } })); - - }); - test('when a logger is passed with option logEvent set to true, it logs the event', async () => { // Prepare @@ -230,6 +232,7 @@ describe('Middy middleware', () => { const logger = new Logger({ customConfigService: configService, }); + const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); const lambdaHandler = (): void => { logger.info('This is an INFO log with some context'); }; @@ -256,8 +259,8 @@ describe('Middy middleware', () => { await handler(event, context, () => console.log('Lambda invoked!')); // Assess - expect(consoleSpy['info']).toBeCalledTimes(2); - expect(consoleSpy['info']).toHaveBeenNthCalledWith(1, JSON.stringify({ + 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, @@ -267,71 +270,68 @@ describe('Middy middleware', () => { message: 'Lambda invocation event', service: 'hello-world', timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: 'abcdef123456abcdef123456abcdef123456', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { foo: 'bar' } })); - - }); }); - describe('Feature: clear state', () => { + 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 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({ + // 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'] } }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribs); + 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); }); }); -}); \ No newline at end of file +}); + From 46bade561e4b9e8bd59b211ddbde0782dfa6e029 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Wed, 22 Jun 2022 14:48:33 +0200 Subject: [PATCH 06/10] test(logger): fix log event unit tests --- packages/logger/tests/unit/Logger.test.ts | 11 +++++++---- packages/logger/tests/unit/middleware/middy.test.ts | 2 +- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index 3ca8c7cdee..f3d495705b 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -1146,12 +1146,14 @@ describe('Class: Logger', () => { // Prepare const logger = new Logger(); + const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); // Act logger.logEventIfEnabled(dummyEvent); // Assess - expect(console['info']).toBeCalledTimes(0); + + expect(consoleSpy).toBeCalledTimes(0); }); test('When the feature is enabled via overwrite flag, it DOES log the event', () => { @@ -1161,18 +1163,19 @@ describe('Class: Logger', () => { something: 'happened!' }; const logger = new Logger(); + const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); // Act logger.logEventIfEnabled(event, true); // Assess - expect(console['info']).toBeCalledTimes(1); - expect(console['info']).toHaveBeenNthCalledWith(1, JSON.stringify({ + expect(consoleSpy).toBeCalledTimes(1); + expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ level: 'INFO', message: 'Lambda invocation event', service: 'hello-world', timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: 'abcdef123456abcdef123456abcdef123456', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { something: 'happened!' } diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index 82f1ad9b72..7c596182a3 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -268,7 +268,7 @@ describe('Middy middleware', () => { function_request_id: awsRequestId, level: 'INFO', message: 'Lambda invocation event', - service: 'hello-world', + service: 'my-backend-service', timestamp: '2016-06-20T12:08:10.000Z', xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', event: { From 68ce02530c1a5ccf6d1b16f6995261c9011e4a1a Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 23 Jun 2022 00:50:58 +0200 Subject: [PATCH 07/10] test(logger): unit + e2e tests for log event functionality --- packages/logger/src/Logger.ts | 10 --- packages/logger/src/config/ConfigService.ts | 4 +- .../basicFeatures.middy.test.FunctionCode.ts | 6 +- .../tests/e2e/basicFeatures.middy.test.ts | 36 +++++++- packages/logger/tests/unit/Logger.test.ts | 1 + .../EnvironmentVariablesService.test.ts | 82 +++++++++++++++++++ packages/logger/tests/unit/helpers.test.ts | 2 +- 7 files changed, 121 insertions(+), 20 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 0655a21080..2d84eebd81 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -358,16 +358,6 @@ class Logger extends Utility implements ClassThatLogs { }); } - /** - * It sets the log event flag value. - * - * @param {number} [sampleRateValue] - * @returns {void} - */ - public setLogEvent(): void { - this.logEvent = this.getCustomConfigService()?.getLogEvent() || this.getEnvVarsService().getLogEvent(); - } - /** * It sets the given attributes (key-value pairs) to all log items generated by this Logger instance. * Note: this replaces the pre-existing value. diff --git a/packages/logger/src/config/ConfigService.ts b/packages/logger/src/config/ConfigService.ts index 6a5d4fed03..6479ab32ee 100644 --- a/packages/logger/src/config/ConfigService.ts +++ b/packages/logger/src/config/ConfigService.ts @@ -75,9 +75,7 @@ abstract class ConfigService implements ConfigServiceInterface { * @protected */ protected isValueTrue(value: string): boolean { - const normalizedValue = value.toLowerCase(); - - return normalizedValue === 'true' || normalizedValue === '1'; + return value.toLowerCase() === 'true' || value === '1'; } } diff --git a/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts b/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts index 30e5323d9a..c434a7892a 100644 --- a/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts +++ b/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts @@ -3,6 +3,7 @@ import { Context, APIGatewayAuthorizerResult } from 'aws-lambda'; import middy from '@middy/core'; const PERSISTENT_KEY = process.env.PERSISTENT_KEY; +const PERSISTENT_KEY_FIRST_INVOCATION_ONLY = process.env.PERSISTENT_KEY_FIRST_INVOCATION_ONLY; const PERSISTENT_VALUE = process.env.PERSISTENT_VALUE; const REMOVABLE_KEY = process.env.REMOVABLE_KEY; const REMOVABLE_VALUE = process.env.REMOVABLE_VALUE; @@ -33,7 +34,7 @@ const testFunction = async (event: LambdaEvent, context: Context): Promise<{requ const specialValue = event.invocation; if (specialValue === 0) { logger.appendKeys({ - specialKey: specialValue + [PERSISTENT_KEY_FIRST_INVOCATION_ONLY]: specialValue }); } @@ -72,4 +73,5 @@ const testFunction = async (event: LambdaEvent, context: Context): Promise<{requ }; }; -export const handler = middy(testFunction).use(injectLambdaContext(logger, { clearState: true })); +export const handler = middy(testFunction) + .use(injectLambdaContext(logger, { clearState: true, logEvent: true })); diff --git a/packages/logger/tests/e2e/basicFeatures.middy.test.ts b/packages/logger/tests/e2e/basicFeatures.middy.test.ts index 921d20ee92..4cd268486f 100644 --- a/packages/logger/tests/e2e/basicFeatures.middy.test.ts +++ b/packages/logger/tests/e2e/basicFeatures.middy.test.ts @@ -42,6 +42,7 @@ const lambdaFunctionCodeFile = 'basicFeatures.middy.test.FunctionCode.ts'; // Text to be used by Logger in the Lambda function const PERSISTENT_KEY = 'persistentKey'; +const PERSISTENT_KEY_FIRST_INVOCATION_ONLY = 'specialKey'; const PERSISTENT_VALUE = `a persistent value that will be put in every log ${uuid}`; const REMOVABLE_KEY = 'removableKey'; const REMOVABLE_VALUE = `a persistent value that will be removed and not displayed in any log ${uuid}`; @@ -73,6 +74,7 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime} // Text to be used by Logger in the Lambda function PERSISTENT_KEY, + PERSISTENT_KEY_FIRST_INVOCATION_ONLY, PERSISTENT_VALUE, REMOVABLE_KEY, REMOVABLE_VALUE, @@ -127,9 +129,7 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime} expect(message).not.toContain(`"cold_start":true`); } }, TEST_CASE_TIMEOUT); - }); - describe('Context data', () => { it('should log context information in every log', async () => { const logMessages = invocationLogs[0].getFunctionLogs(); @@ -143,6 +143,34 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime} }, TEST_CASE_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); + + }); + describe('Persistent additional log keys and values', () => { it('should contain persistent value in every log', async () => { const logMessages = invocationLogs[0].getFunctionLogs(); @@ -163,12 +191,12 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime} it('with clear state enabled, should not persist keys across invocations', async () => { const firstInvocationMessages = invocationLogs[0].getFunctionLogs(); for (const message of firstInvocationMessages) { - expect(message).toContain(`"specialKey":0`); + expect(message).toContain(`"${PERSISTENT_KEY_FIRST_INVOCATION_ONLY}":0`); } const secondInvocationMessages = invocationLogs[1].getFunctionLogs(); for (const message of secondInvocationMessages) { - expect(message).not.toContain(`"specialKey":0`); + expect(message).not.toContain(`"${PERSISTENT_KEY_FIRST_INVOCATION_ONLY}":0`); } }, TEST_CASE_TIMEOUT); }); diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index f3d495705b..8fe30c7bc2 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -809,6 +809,7 @@ describe('Class: Logger', () => { test('when used as decorator, it returns a function with the correct scope of the decorated class', async () => { // Prepare + const logger = new Logger(); const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); class LambdaFunction implements LambdaInterface { diff --git a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts index ab810089c8..18d1e29221 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -136,6 +136,88 @@ describe('Class: EnvironmentVariablesService', () => { }); + describe('Method: getLogEvent', () => { + + test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "true"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(true); + }); + + test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "TRUE"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'TRUE'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(true); + }); + + test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "1"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = '1'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(true); + }); + + test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "false"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'false'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(false); + }); + + test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "0"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = '0'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(false); + }); + + test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "somethingsilly"', () => { + + // Prepare + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'somethingsilly'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogEvent(); + + // Assess + expect(value).toEqual(false); + }); + + }); + describe('Method: getLogLevel', () => { test('It returns the value of the environment variable LOG_LEVEL', () => { diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index 4217fe321c..9309bea207 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -296,7 +296,7 @@ describe('Helper: createLogger function', () => { return 'dev'; }, getLogEvent(): boolean { - return false; + return true; }, getLogLevel(): string { return 'INFO'; From 01ed9bd66e1593bfa59134ca1b091748f3bfd5eb Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 23 Jun 2022 12:42:14 +0200 Subject: [PATCH 08/10] docs(logger): add log event --- docs/core/logger.md | 50 +++++++++++++++++-- docs/index.md | 28 +++++------ .../commons/tests/utils/InvocationLogs.ts | 8 +++ 3 files changed, 69 insertions(+), 17 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index fb1c02aed4..621e4c58e1 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -14,9 +14,9 @@ Logger provides an opinionated logger with output structured as JSON. ## Key features -* Capture key fields from Lambda context, cold start and structures logging output as JSON -* Log Lambda context when instructed (disabled by default) -* Log sampling prints all logs for a percentage of invocations (disabled by default) +* Capture key fields from Lambda context, cold start and structure logging output as JSON +* Log Lambda event when instructed (disabled by default) +* Log sampling prints all the logs for a percentage of invocations (disabled by default) * Append additional keys to structured log at any point in time ## Getting started @@ -193,6 +193,50 @@ In each case, the printed log will look like this: } ``` +#### Log incoming event + +When debugging in non-production environments, you can instruct Logger to log the incoming event with the middleware/decorator parameter `logEvent` or via POWERTOOLS_LOGGER_LOG_EVENT env var set to `true`. + +???+ warning +This is disabled by default to prevent sensitive info being logged + +=== "Middy Middleware" + + ```typescript hl_lines="11" + import { Logger, injectLambdaContext } from '@aws-lambda-powertools/logger'; + import middy from '@middy/core'; + + const logger = new Logger(); + + const lambdaHandler = async (_event: any, _context: any): Promise => { + logger.info('This is an INFO log with some context'); + }; + + export const handler = middy(lambdaHandler) + .use(injectLambdaContext(logger, { logEvent: true })); + ``` + +=== "Decorator" + + ```typescript hl_lines="8" + import { Logger } from '@aws-lambda-powertools/logger'; + import { LambdaInterface } from '@aws-lambda-powertools/commons'; + + const logger = new Logger(); + + class Lambda implements LambdaInterface { + // Set the log event flag to true + @logger.injectLambdaContext({ logEvent: true }) + public async handler(_event: any, _context: any): Promise { + logger.info('This is an INFO log with some context'); + } + + } + + export const myFunction = new Lambda(); + export const handler = myFunction.handler; + ``` + ### Appending persistent additional log keys and values You can append additional persistent keys and values in the logs generated during a Lambda invocation using either mechanism: diff --git a/docs/index.md b/docs/index.md index aace91263e..58e8150ae9 100644 --- a/docs/index.md +++ b/docs/index.md @@ -45,20 +45,20 @@ Each TypeScript utility is installed as standalone NPM package. ## Environment variables !!! info - **Explicit parameters take precedence over environment variables.** - -| Environment variable | Description | Utility | Default | -|-------------------------------------------| --------------------------------------------------------------------------------- |---------------------------|-----------------------| -| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | `"service_undefined"` | -| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | `None` | -| **POWERTOOLS_TRACE_ENABLED** | Explicitly disables tracing | [Tracer](./core/tracer) | `true` | -| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Captures Lambda or method return as metadata. | [Tracer](./core/tracer) | `true` | -| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Captures Lambda or method exception as metadata. | [Tracer](./core/tracer) | `true` | -| **POWERTOOLS_TRACER_CAPTURE_HTTPS_REQUESTS** | Captures HTTP(s) requests as segments. | [Tracer](./core/tracer) | `true` | -| **POWERTOOLS_LOGGER_LOG_EVENT** | Logs incoming event | [Logger](./core/logger) | `false` | -| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](./core/logger) | `0` | -| **POWERTOOLS_LOG_DEDUPLICATION_DISABLED** | Disables log deduplication filter protection to use Pytest Live Log feature | [Logger](./core/logger) | `false` | -| **LOG_LEVEL** | Sets logging level | [Logger](./core/logger) | `INFO` | + **Explicit parameters passed in constructors or take precedence over environment variables.** + +| Environment variable | Description | Utility | Default | +|----------------------------------------------|----------------------------------------------------------------------------------------|---------------------------|-----------------------| +| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | `"service_undefined"` | +| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | `None` | +| **POWERTOOLS_TRACE_ENABLED** | Explicitly disables tracing | [Tracer](./core/tracer) | `true` | +| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Captures Lambda or method return as metadata. | [Tracer](./core/tracer) | `true` | +| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Captures Lambda or method exception as metadata. | [Tracer](./core/tracer) | `true` | +| **POWERTOOLS_TRACER_CAPTURE_HTTPS_REQUESTS** | Captures HTTP(s) requests as segments. | [Tracer](./core/tracer) | `true` | +| **POWERTOOLS_LOGGER_LOG_EVENT** | Logs incoming event | [Logger](./core/logger) | `false` | +| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](./core/logger) | `0` | +| **POWERTOOLS_LOGGER_LOG_EVENT** | Logs incoming events | [Logger](./core/logger) | `false` | +| **LOG_LEVEL** | Sets logging level | [Logger](./core/logger) | `INFO` | ## Examples diff --git a/packages/commons/tests/utils/InvocationLogs.ts b/packages/commons/tests/utils/InvocationLogs.ts index 22e1334007..52d8656e40 100644 --- a/packages/commons/tests/utils/InvocationLogs.ts +++ b/packages/commons/tests/utils/InvocationLogs.ts @@ -56,6 +56,14 @@ export class InvocationLogs { return filteredLogs.length > 0; } + /** + * Return all the log of the function + * @returns Array of function logs + */ + public getAllFunctionLogs(): string[] { + return this.logs; + } + /** * Return only logs from function, exclude START, END, and REPORT generated by Lambda service * @param levelToFilter level to filter From d887485314e8910ea4bdb765b41b42bb602d748d Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 23 Jun 2022 14:27:20 +0200 Subject: [PATCH 09/10] docs: add single line command for docs generation --- CONTRIBUTING.md | 6 +++++- package.json | 2 ++ 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 90921e6df3..bcd69bf3e2 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -238,7 +238,11 @@ You can build and start the API reference website by running these two commands #### Docs website -You can build and start a local docs website by running these two commands: +You can build and start a local docs website by running: + +`npm run docs-website-build-run` + +Alternatively you can run these two commands: * `npm run docs-buildDockerImage` OR `docker build -t squidfunk/mkdocs-material ./docs/` * `npm run docs-runLocalDocker` OR `docker run --rm -it -p 8000:8000 -v ${PWD}:/docs squidfunk/mkdocs-material` diff --git a/package.json b/package.json index ca9db89246..19329e669a 100644 --- a/package.json +++ b/package.json @@ -29,8 +29,10 @@ "lerna-preversion": "lerna exec -- npm run lint", "lerna-version": "lerna exec -- npm run format && git add -A src", "postversion": "git push && git push --tags", + "docs-website-build-run": "npm run docs-buildDockerImage && npm run docs-runLocalDocker", "docs-buildDockerImage": "docker build -t powertool-typescript/docs ./docs/", "docs-runLocalDocker": "docker run --rm -it -p 8000:8000 -v ${PWD}:/docs powertool-typescript/docs", + "docs-api-build-run": "npm run docs-generateApiDoc && npx live-server api", "docs-generateApiDoc": "typedoc .", "docs-runLocalApiDoc": "npx live-server api" }, From 8d50e5cdc7ba8509ad302e524386b722693d1505 Mon Sep 17 00:00:00 2001 From: Sara Gerion Date: Thu, 23 Jun 2022 14:36:34 +0200 Subject: [PATCH 10/10] docs: fix typo in env vars section --- docs/index.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/index.md b/docs/index.md index 58e8150ae9..60fb5d621a 100644 --- a/docs/index.md +++ b/docs/index.md @@ -45,7 +45,7 @@ Each TypeScript utility is installed as standalone NPM package. ## Environment variables !!! info - **Explicit parameters passed in constructors or take precedence over environment variables.** + **Explicit parameters passed in constructors or in middleware/decorators take precedence over environment variables.** | Environment variable | Description | Utility | Default | |----------------------------------------------|----------------------------------------------------------------------------------------|---------------------------|-----------------------|