diff --git a/packages/logger/.eslintrc.js b/packages/logger/.eslintrc.js new file mode 100644 index 0000000000..2e4ca18fb2 --- /dev/null +++ b/packages/logger/.eslintrc.js @@ -0,0 +1,72 @@ +module.exports = { + env: { + browser: false, + es2020: true, + jest: true, + node: true, + }, + ignorePatterns: ['coverage', 'lib'], + extends: [ + 'plugin:@typescript-eslint/recommended', + 'plugin:prettier/recommended', + ], + parser: '@typescript-eslint/parser', + plugins: ['@typescript-eslint', 'prettier'], + settings: { + 'import/resolver': { + node: {}, + typescript: { + project: './tsconfig.json', + alwaysTryTypes: true, + }, + }, + }, + rules: { + '@typescript-eslint/explicit-function-return-type': [ + 'error', + { allowExpressions: true }, + ], // Enforce return type definitions for functions + '@typescript-eslint/explicit-member-accessibility': 'error', // Enforce explicit accessibility modifiers on class properties and methods (public, private, protected) + '@typescript-eslint/member-ordering': [ + // Standardize the order of class members + 'error', + { + default: { + memberTypes: [ + 'signature', + 'public-field', + 'protected-field', + 'private-field', + 'constructor', + 'public-method', + 'protected-method', + 'private-method', + ], + order: 'alphabetically', + }, + }, + ], + '@typescript-eslint/no-explicit-any': 'error', // Disallow usage of the any type + '@typescript-eslint/no-unused-vars': ['error', { argsIgnorePattern: '^_' }], // Disallow unused variables, except for variables starting with an underscore + '@typescript-eslint/no-use-before-define': ['off'], // Check if this rule is needed + 'no-unused-vars': 'off', // Disable eslint core rule, since it's replaced by @typescript-eslint/no-unused-vars + // Rules from eslint core https://eslint.org/docs/latest/rules/ + 'array-bracket-spacing': ['error', 'never'], // Disallow spaces inside of array brackets + 'computed-property-spacing': ['error', 'never'], // Disallow spaces inside of computed properties + 'func-style': ['warn', 'expression'], // Enforce function expressions instead of function declarations + 'keyword-spacing': 'error', // Enforce spaces after keywords and before parenthesis, e.g. if (condition) instead of if(condition) + 'padding-line-between-statements': [ + // Require an empty line before return statements + 'error', + { blankLine: 'always', prev: '*', next: 'return' }, + ], + 'no-console': 0, // Allow console.log statements + 'no-multi-spaces': ['error', { ignoreEOLComments: false }], // Disallow multiple spaces except for comments + 'no-multiple-empty-lines': ['error', { max: 1, maxBOF: 0, maxEOF: 0 }], // Enforce no empty line at the beginning & end of files and max 1 empty line between consecutive statements + 'no-throw-literal': 'error', // Disallow throwing literals as exceptions, e.g. throw 'error' instead of throw new Error('error') + 'object-curly-spacing': ['error', 'always'], // Enforce spaces inside of curly braces in objects + 'prefer-arrow-callback': 'error', // Enforce arrow functions instead of anonymous functions for callbacks + quotes: ['error', 'single', { allowTemplateLiterals: true }], // Enforce single quotes except for template strings + semi: ['error', 'always'], // Require semicolons instead of ASI (automatic semicolon insertion) at the end of statements + }, +}; diff --git a/packages/logger/jest.config.js b/packages/logger/jest.config.js index 8ed8012be5..cde674c939 100644 --- a/packages/logger/jest.config.js +++ b/packages/logger/jest.config.js @@ -3,43 +3,26 @@ module.exports = { name: 'AWS Lambda Powertools utility: LOGGER', color: 'cyan', }, - 'runner': 'groups', - 'preset': 'ts-jest', - 'transform': { + runner: 'groups', + preset: 'ts-jest', + transform: { '^.+\\.ts?$': 'ts-jest', }, - moduleFileExtensions: [ 'js', 'ts' ], - 'collectCoverageFrom': [ - '**/src/**/*.ts', - '!**/node_modules/**', - ], - 'testMatch': ['**/?(*.)+(spec|test).ts'], - 'roots': [ - '/src', - '/tests', - ], - 'testPathIgnorePatterns': [ - '/node_modules/', - ], - 'testEnvironment': 'node', - 'coveragePathIgnorePatterns': [ - '/node_modules/', - '/types/', - ], - 'coverageThreshold': { - 'global': { - 'statements': 100, - 'branches': 100, - 'functions': 100, - 'lines': 100, + moduleFileExtensions: ['js', 'ts'], + collectCoverageFrom: ['**/src/**/*.ts', '!**/node_modules/**'], + testMatch: ['**/?(*.)+(spec|test).ts'], + roots: ['/src', '/tests'], + testPathIgnorePatterns: ['/node_modules/'], + testEnvironment: 'node', + coveragePathIgnorePatterns: ['/node_modules/', '/types/'], + coverageThreshold: { + global: { + statements: 100, + branches: 100, + functions: 100, + lines: 100, }, }, - 'coverageReporters': [ - 'json-summary', - 'text', - 'lcov' - ], - 'setupFiles': [ - '/tests/helpers/populateEnvironmentVariables.ts' - ] -}; \ No newline at end of file + coverageReporters: ['json-summary', 'text', 'lcov'], + setupFiles: ['/tests/helpers/populateEnvironmentVariables.ts'], +}; diff --git a/packages/logger/package.json b/packages/logger/package.json index c67ac3180a..bb01a2631f 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -19,14 +19,15 @@ "test:e2e": "jest --group=e2e", "watch": "jest --watch --group=unit", "build": "tsc", - "lint": "eslint --ext .ts --no-error-on-unmatched-pattern src tests", - "lint-fix": "eslint --fix --ext .ts --no-error-on-unmatched-pattern src tests", + "lint": "eslint --ext .ts,.js --no-error-on-unmatched-pattern .", + "lint-fix": "eslint --fix --ext .ts,.js --no-error-on-unmatched-pattern .", "package": "mkdir -p dist/ && npm pack && mv *.tgz dist/", "package-bundle": "../../package-bundler.sh logger-bundle ./dist", "prepare": "npm run build" }, "lint-staged": { - "*.ts": "npm run lint-fix" + "*.ts": "npm run lint-fix", + "*.js": "npm run lint-fix" }, "homepage": "https://github.com/awslabs/aws-lambda-powertools-typescript/tree/main/packages/logging#readme", "license": "MIT", @@ -59,4 +60,4 @@ "serverless", "nodejs" ] -} +} \ No newline at end of file diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 278245cba1..e9f2fd7be6 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -44,7 +44,7 @@ import type { * // Logger parameters fetched from the environment variables: * const logger = new Logger(); * ``` - * + * * ### Functions usage with middleware * * If you use function-based Lambda handlers you can use the [injectLambdaContext()](#injectLambdaContext) @@ -76,9 +76,9 @@ import type { * const logger = new Logger(); * * class Lambda implements LambdaInterface { - * + * * // FYI: Decorator might not render properly in VSCode mouse over due to https://github.com/microsoft/TypeScript/issues/47679 and might show as *@logger* instead of `@logger.injectLambdaContext` - * + * * // Decorate your handler class method * @logger.injectLambdaContext() * public async handler(_event: any, _context: any): Promise { @@ -89,7 +89,7 @@ import type { * const handlerClass = new Lambda(); * export const handler = handlerClass.handler.bind(handlerClass); * ``` - * + * * ### Functions usage with manual instrumentation * * If you prefer to manually instrument your Lambda handler you can use the methods in the Logger class directly. @@ -111,7 +111,6 @@ import type { * @see https://awslabs.github.io/aws-lambda-powertools-typescript/latest/core/logger/ */ class Logger extends Utility implements ClassThatLogs { - // console is initialized in the constructor in setOptions() private console!: Console; @@ -122,7 +121,7 @@ class Logger extends Utility implements ClassThatLogs { // envVarsService is always initialized in the constructor in setOptions() private envVarsService!: EnvironmentVariablesService; - private logEvent: boolean = false; + private logEvent = false; private logFormatter?: LogFormatterInterface; @@ -140,7 +139,7 @@ class Logger extends Utility implements ClassThatLogs { SILENT: 28, }; - private logsSampled: boolean = false; + private logsSampled = false; private persistentLogAttributes?: LogAttributes = {}; @@ -212,7 +211,9 @@ class Logger extends Utility implements ClassThatLogs { logFormatter: this.getLogFormatter(), }; const parentsPowertoolsLogData = this.getPowertoolLogData(); - const childLogger = new Logger(merge(parentsOptions, parentsPowertoolsLogData, options)); + const childLogger = new Logger( + merge(parentsOptions, parentsPowertoolsLogData, options) + ); const parentsPersistentLogAttributes = this.getPersistentLogAttributes(); childLogger.addPersistentLogAttributes(parentsPersistentLogAttributes); @@ -226,11 +227,14 @@ class Logger extends Utility implements ClassThatLogs { /** * It prints a log item with level CRITICAL. - * + * * @param {LogItemMessage} input * @param {Error | LogAttributes | string} extraInput */ - public critical(input: LogItemMessage, ...extraInput: LogItemExtraInput): void { + public critical( + input: LogItemMessage, + ...extraInput: LogItemExtraInput + ): void { this.processLogItem('CRITICAL', input, extraInput); } @@ -283,7 +287,7 @@ class Logger extends Utility implements ClassThatLogs { * @returns {LogAttributes} */ public getPersistentLogAttributes(): LogAttributes { - return this.persistentLogAttributes; + return this.persistentLogAttributes as LogAttributes; } /** @@ -300,13 +304,13 @@ class Logger extends Utility implements ClassThatLogs { /** * Method decorator that adds the current Lambda function context as extra * information in all log items. - * + * * The decorator can be used only when attached to a Lambda function handler which * is written as method of a class, and should be declared just before the handler declaration. * * Note: Currently TypeScript only supports decorators on classes and methods. If you are using the * function syntax, you should use the middleware instead. - * + * * @example * ```typescript * import { Logger } from '@aws-lambda-powertools/logger'; @@ -325,7 +329,7 @@ class Logger extends Utility implements ClassThatLogs { * const handlerClass = new Lambda(); * export const handler = handlerClass.handler.bind(handlerClass); * ``` - * + * * @see https://www.typescriptlang.org/docs/handbook/decorators.html#method-decorators * @returns {HandlerMethodDecorator} */ @@ -341,36 +345,55 @@ class Logger extends Utility implements ClassThatLogs { const loggerRef = this; // Use a function() {} instead of an () => {} arrow function so that we can // access `myClass` as `this` in a decorated `myClass.myMethod()`. - descriptor.value = (async function (this: Handler, event, context, callback) { - + descriptor.value = async function ( + this: Handler, + event, + context, + callback + ) { let initialPersistentAttributes = {}; if (options && options.clearState === true) { - initialPersistentAttributes = { ...loggerRef.getPersistentLogAttributes() }; + initialPersistentAttributes = { + ...loggerRef.getPersistentLogAttributes(), + }; } Logger.injectLambdaContextBefore(loggerRef, event, context, options); let result: unknown; try { - result = await originalMethod.apply(this, [ event, context, callback ]); + result = await originalMethod.apply(this, [event, context, callback]); } catch (error) { throw error; } finally { - Logger.injectLambdaContextAfterOrOnError(loggerRef, initialPersistentAttributes, options); + Logger.injectLambdaContextAfterOrOnError( + loggerRef, + initialPersistentAttributes, + options + ); } return result; - }); + }; }; } - public static injectLambdaContextAfterOrOnError(logger: Logger, initialPersistentAttributes: LogAttributes, options?: HandlerOptions): void { + public static injectLambdaContextAfterOrOnError( + logger: Logger, + initialPersistentAttributes: LogAttributes, + options?: HandlerOptions + ): void { if (options && options.clearState === true) { logger.setPersistentLogAttributes(initialPersistentAttributes); } } - public static injectLambdaContextBefore(logger: Logger, event: unknown, context: Context, options?: HandlerOptions): void { + public static injectLambdaContextBefore( + logger: Logger, + event: unknown, + context: Context, + options?: HandlerOptions + ): void { logger.addContext(context); let shouldLogEvent = undefined; @@ -487,7 +510,9 @@ class Logger extends Utility implements ClassThatLogs { * @private * @returns {void} */ - private addToPowertoolLogData(...attributesArray: Array>): void { + private addToPowertoolLogData( + ...attributesArray: Array> + ): void { attributesArray.forEach((attributes: Partial) => { merge(this.powertoolLogData, attributes); }); @@ -504,17 +529,26 @@ class Logger extends Utility implements ClassThatLogs { * @param {LogItemExtraInput} extraInput * @returns {LogItem} */ - private createAndPopulateLogItem(logLevel: LogLevel, input: LogItemMessage, extraInput: LogItemExtraInput): LogItem { + private createAndPopulateLogItem( + logLevel: LogLevel, + input: LogItemMessage, + extraInput: LogItemExtraInput + ): LogItem { // TODO: this method's logic is hard to understand, there is an opportunity here to simplify this logic. - const unformattedBaseAttributes = merge({ - logLevel, - timestamp: new Date(), - message: typeof input === 'string' ? input : input.message, - xRayTraceId: this.envVarsService.getXrayTraceId(), - }, this.getPowertoolLogData()); + const unformattedBaseAttributes = merge( + { + logLevel, + timestamp: new Date(), + message: typeof input === 'string' ? input : input.message, + xRayTraceId: this.envVarsService.getXrayTraceId(), + }, + this.getPowertoolLogData() + ); const logItem = new LogItem({ - baseAttributes: this.getLogFormatter().formatAttributes(unformattedBaseAttributes), + baseAttributes: this.getLogFormatter().formatAttributes( + unformattedBaseAttributes + ), persistentAttributes: this.getPersistentLogAttributes(), }); @@ -524,9 +558,11 @@ class Logger extends Utility implements ClassThatLogs { } extraInput.forEach((item: Error | LogAttributes | string) => { const attributes: LogAttributes = - item instanceof Error ? { error: item } : - typeof item === 'string' ? { extra: item } : - item; + item instanceof Error + ? { error: item } + : typeof item === 'string' + ? { extra: item } + : item; logItem.addAttributes(attributes); }); @@ -551,7 +587,7 @@ class Logger extends Utility implements ClassThatLogs { * @returns {EnvironmentVariablesService} */ private getEnvVarsService(): EnvironmentVariablesService { - return this.envVarsService; + return this.envVarsService as EnvironmentVariablesService; } /** @@ -562,12 +598,12 @@ class Logger extends Utility implements ClassThatLogs { * @returns {LogFormatterInterface} */ private getLogFormatter(): LogFormatterInterface { - return this.logFormatter; + return this.logFormatter as LogFormatterInterface; } /** * It returns the log level set for the Logger instance. - * + * * Even though logLevel starts as undefined, it will always be set to a value * during the Logger instance's initialization. So, we can safely use the non-null * assertion operator here. @@ -599,9 +635,12 @@ class Logger extends Utility implements ClassThatLogs { * @see https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/JSON/stringify#exceptions * @private */ - private getReplacer(): (key: string, value: LogAttributes | Error | bigint) => void { + private getReplacer(): ( + key: string, + value: LogAttributes | Error | bigint + ) => void { const references = new WeakSet(); - + return (key, value) => { let item = value; if (item instanceof Error) { @@ -616,7 +655,7 @@ class Logger extends Utility implements ClassThatLogs { } references.add(item); } - + return item; }; } @@ -632,9 +671,9 @@ class Logger extends Utility implements ClassThatLogs { this.setSampleRateValue(); } - return this.powertoolLogData.sampleRateValue; + return this.powertoolLogData.sampleRateValue as number; } - + /** * It returns true and type guards the log level if a given log level is valid. * @@ -642,7 +681,9 @@ class Logger extends Utility implements ClassThatLogs { * @private * @returns {boolean} */ - private isValidLogLevel(logLevel?: LogLevel | string): logLevel is Uppercase { + private isValidLogLevel( + logLevel?: LogLevel | string + ): logLevel is Uppercase { return typeof logLevel === 'string' && logLevel in this.logLevelThresholds; } @@ -657,11 +698,17 @@ class Logger extends Utility implements ClassThatLogs { log.prepareForPrint(); const consoleMethod = - logLevel === 'CRITICAL' ? - 'error' : - logLevel.toLowerCase() as keyof Omit; - - this.console[consoleMethod](JSON.stringify(log.getAttributes(), this.getReplacer(), this.logIndentation)); + logLevel === 'CRITICAL' + ? 'error' + : (logLevel.toLowerCase() as keyof Omit); + + this.console[consoleMethod]( + JSON.stringify( + log.getAttributes(), + this.getReplacer(), + this.logIndentation + ) + ); } /** @@ -672,11 +719,18 @@ class Logger extends Utility implements ClassThatLogs { * @param {LogItemExtraInput} extraInput * @private */ - private processLogItem(logLevel: Uppercase, input: LogItemMessage, extraInput: LogItemExtraInput): void { + private processLogItem( + logLevel: Uppercase, + input: LogItemMessage, + extraInput: LogItemExtraInput + ): void { if (!this.shouldPrint(logLevel)) { return; } - this.printLog(logLevel, this.createAndPopulateLogItem(logLevel, input, extraInput)); + this.printLog( + logLevel, + this.createAndPopulateLogItem(logLevel, input, extraInput) + ); } /** @@ -688,7 +742,10 @@ class Logger extends Utility implements ClassThatLogs { */ private setConsole(): void { if (!this.getEnvVarsService().isDevMode()) { - this.console = new Console({ stdout: process.stdout, stderr: process.stderr }); + this.console = new Console({ + stdout: process.stdout, + stderr: process.stderr, + }); } else { this.console = console; } @@ -702,8 +759,12 @@ class Logger extends Utility implements ClassThatLogs { * @param {ConfigServiceInterface} customConfigService * @returns {void} */ - private setCustomConfigService(customConfigService?: ConfigServiceInterface): void { - this.customConfigService = customConfigService ? customConfigService : undefined; + private setCustomConfigService( + customConfigService?: ConfigServiceInterface + ): void { + this.customConfigService = customConfigService + ? customConfigService + : undefined; } /** @@ -711,7 +772,6 @@ class Logger extends Utility implements ClassThatLogs { * to fetch environment variables. * * @private - * @param {ConfigServiceInterface} customConfigService * @returns {void} */ private setEnvVarsService(): void { @@ -778,9 +838,7 @@ class Logger extends Utility implements ClassThatLogs { return; } - const envVarsValue = this.getEnvVarsService() - ?.getLogLevel() - ?.toUpperCase(); + const envVarsValue = this.getEnvVarsService()?.getLogLevel()?.toUpperCase(); if (this.isValidLogLevel(envVarsValue)) { this.logLevel = envVarsValue; @@ -800,7 +858,9 @@ class Logger extends Utility implements ClassThatLogs { private setLogsSampled(): void { const sampleRateValue = this.getSampleRateValue(); // TODO: revisit Math.random() as it's not a real randomization - this.logsSampled = sampleRateValue !== undefined && (sampleRateValue === 1 || Math.random() < sampleRateValue); + this.logsSampled = + sampleRateValue !== undefined && + (sampleRateValue === 1 || Math.random() < sampleRateValue); } /** @@ -833,7 +893,7 @@ class Logger extends Utility implements ClassThatLogs { this.setPowertoolLogData(serviceName, environment); this.setLogEvent(); this.setLogIndentation(); - + this.addPersistentLogAttributes(persistentLogAttributes); return this; @@ -851,7 +911,7 @@ class Logger extends Utility implements ClassThatLogs { private setPowertoolLogData( serviceName?: string, environment?: Environment, - persistentLogAttributes: LogAttributes = {}, + persistentLogAttributes: LogAttributes = {} ): void { this.addToPowertoolLogData( { @@ -862,9 +922,12 @@ class Logger extends Utility implements ClassThatLogs { this.getEnvVarsService().getCurrentEnvironment(), sampleRateValue: this.getSampleRateValue(), serviceName: - serviceName || this.getCustomConfigService()?.getServiceName() || this.getEnvVarsService().getServiceName() || this.getDefaultServiceName(), + serviceName || + this.getCustomConfigService()?.getServiceName() || + this.getEnvVarsService().getServiceName() || + this.getDefaultServiceName(), }, - persistentLogAttributes, + persistentLogAttributes ); } diff --git a/packages/logger/src/config/ConfigServiceInterface.ts b/packages/logger/src/config/ConfigServiceInterface.ts index d66d4e9f85..3b6c25e7db 100644 --- a/packages/logger/src/config/ConfigServiceInterface.ts +++ b/packages/logger/src/config/ConfigServiceInterface.ts @@ -6,56 +6,55 @@ * @see https://awslabs.github.io/aws-lambda-powertools-typescript/latest/#environment-variables */ interface ConfigServiceInterface { - /** * It returns the value of an environment variable that has given name. * * @param {string} name * @returns {string} */ - get(name: string): string + get(name: string): string; /** * It returns the value of the ENVIRONMENT environment variable. * * @returns {string} */ - getCurrentEnvironment(): string + getCurrentEnvironment(): string; /** * It returns the value of the POWERTOOLS_LOGGER_LOG_EVENT environment variable. * * @returns {boolean} */ - getLogEvent(): boolean + getLogEvent(): boolean; /** * It returns the value of the LOG_LEVEL environment variable. * * @returns {string} */ - getLogLevel(): string + getLogLevel(): string; /** * It returns the value of the POWERTOOLS_LOGGER_SAMPLE_RATE environment variable. * * @returns {string|undefined} */ - getSampleRateValue(): number | undefined + getSampleRateValue(): number | undefined; /** * It returns the value of the POWERTOOLS_SERVICE_NAME environment variable. * * @returns {string} */ - getServiceName(): string + getServiceName(): string; /** * It returns the value of the POWERTOOLS_DEV environment variable. * * @returns {boolean} */ - isDevMode(): boolean + isDevMode(): boolean; /** * It returns true if the string value represents a boolean true value. @@ -63,10 +62,7 @@ interface ConfigServiceInterface { * @param {string} value * @returns boolean */ - isValueTrue(value: string): boolean - + isValueTrue(value: string): boolean; } -export { - ConfigServiceInterface, -}; \ No newline at end of file +export { ConfigServiceInterface }; diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index c7813539e0..0472449455 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -15,8 +15,10 @@ import { EnvironmentVariablesService as CommonEnvironmentVariablesService } from * @see https://docs.aws.amazon.com/lambda/latest/dg/configuration-envvars.html#configuration-envvars-runtime * @see https://awslabs.github.io/aws-lambda-powertools-typescript/latest/#environment-variables */ -class EnvironmentVariablesService extends CommonEnvironmentVariablesService implements ConfigServiceInterface { - +class EnvironmentVariablesService + extends CommonEnvironmentVariablesService + implements ConfigServiceInterface +{ // Reserved environment variables private awsRegionVariable = 'AWS_REGION'; private currentEnvironmentVariable = 'ENVIRONMENT'; @@ -82,7 +84,7 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl */ public getLogEvent(): boolean { const value = this.get(this.logEventVariable); - + return this.isValueTrue(value); } @@ -103,7 +105,7 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl public getSampleRateValue(): number | undefined { const value = this.get(this.sampleRateValueVariable); - return (value && value.length > 0) ? Number(value) : undefined; + return value && value.length > 0 ? Number(value) : undefined; } /** @@ -116,9 +118,6 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl return this.isValueTrue(value); } - } -export { - EnvironmentVariablesService, -}; \ No newline at end of file +export { EnvironmentVariablesService }; diff --git a/packages/logger/src/config/index.ts b/packages/logger/src/config/index.ts index 0f036d810e..11fd37677e 100644 --- a/packages/logger/src/config/index.ts +++ b/packages/logger/src/config/index.ts @@ -1,2 +1,2 @@ export * from './ConfigServiceInterface'; -export * from './EnvironmentVariablesService'; \ No newline at end of file +export * from './EnvironmentVariablesService'; diff --git a/packages/logger/src/formatter/LogFormatter.ts b/packages/logger/src/formatter/LogFormatter.ts index 29b47f99fd..dac142a05a 100644 --- a/packages/logger/src/formatter/LogFormatter.ts +++ b/packages/logger/src/formatter/LogFormatter.ts @@ -9,14 +9,15 @@ import { LogAttributes, UnformattedAttributes } from '../types'; * @implements {LogFormatterInterface} */ abstract class LogFormatter implements LogFormatterInterface { - /** * It formats key-value pairs of log attributes. * * @param {UnformattedAttributes} attributes * @returns {LogAttributes} */ - public abstract formatAttributes(attributes: UnformattedAttributes): LogAttributes; + public abstract formatAttributes( + attributes: UnformattedAttributes + ): LogAttributes; /** * It formats a given Error parameter. @@ -64,13 +65,10 @@ abstract class LogFormatter implements LogFormatterInterface { if (Array.isArray(match)) { return `${match[1]}:${Number(match[2])}`; } - } return ''; } } -export { - LogFormatter, -}; \ No newline at end of file +export { LogFormatter }; diff --git a/packages/logger/src/formatter/LogFormatterInterface.ts b/packages/logger/src/formatter/LogFormatterInterface.ts index 1139443c28..b6a771b84e 100644 --- a/packages/logger/src/formatter/LogFormatterInterface.ts +++ b/packages/logger/src/formatter/LogFormatterInterface.ts @@ -4,14 +4,13 @@ import { LogAttributes, UnformattedAttributes } from '../types'; * @interface */ interface LogFormatterInterface { - /** * It formats key-value pairs of log attributes. * * @param {UnformattedAttributes} attributes * @returns {PowertoolLog} */ - formatAttributes(attributes: UnformattedAttributes): LogAttributes + formatAttributes(attributes: UnformattedAttributes): LogAttributes; /** * It formats a given Error parameter. @@ -19,10 +18,7 @@ interface LogFormatterInterface { * @param {Error} error * @returns {LogAttributes} */ - formatError(error: Error): LogAttributes - + formatError(error: Error): LogAttributes; } -export { - LogFormatterInterface, -}; \ No newline at end of file +export { LogFormatterInterface }; diff --git a/packages/logger/src/formatter/PowertoolLogFormatter.ts b/packages/logger/src/formatter/PowertoolLogFormatter.ts index c4bd7bc34b..0fa77928e2 100644 --- a/packages/logger/src/formatter/PowertoolLogFormatter.ts +++ b/packages/logger/src/formatter/PowertoolLogFormatter.ts @@ -10,7 +10,6 @@ import { PowertoolLog } from '../types/formats'; * @extends {LogFormatter} */ class PowertoolLogFormatter extends LogFormatter { - /** * It formats key-value pairs of log attributes. * @@ -32,9 +31,6 @@ class PowertoolLogFormatter extends LogFormatter { xray_trace_id: attributes.xRayTraceId, }; } - } -export { - PowertoolLogFormatter, -}; \ No newline at end of file +export { PowertoolLogFormatter }; diff --git a/packages/logger/src/formatter/index.ts b/packages/logger/src/formatter/index.ts index 4c88132ead..1f7f14d2ab 100644 --- a/packages/logger/src/formatter/index.ts +++ b/packages/logger/src/formatter/index.ts @@ -1,3 +1,3 @@ export * from './LogFormatter'; export * from './LogFormatterInterface'; -export * from './PowertoolLogFormatter'; \ No newline at end of file +export * from './PowertoolLogFormatter'; diff --git a/packages/logger/src/helpers.ts b/packages/logger/src/helpers.ts index 9ddd10009e..e143f83834 100644 --- a/packages/logger/src/helpers.ts +++ b/packages/logger/src/helpers.ts @@ -1,8 +1,7 @@ import { Logger } from '.'; import { ConstructorOptions } from './types'; -const createLogger = (options: ConstructorOptions = {}): Logger => new Logger(options); +const createLogger = (options: ConstructorOptions = {}): Logger => + new Logger(options); -export { - createLogger, -}; \ No newline at end of file +export { createLogger }; diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 577d19f6d5..caa720368d 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,4 +1,4 @@ export * from './helpers'; export * from './Logger'; export * from './middleware'; -export * from './formatter'; \ No newline at end of file +export * from './formatter'; diff --git a/packages/logger/src/log/LogItem.ts b/packages/logger/src/log/LogItem.ts index 68b27f1f86..1c562ec171 100644 --- a/packages/logger/src/log/LogItem.ts +++ b/packages/logger/src/log/LogItem.ts @@ -3,10 +3,12 @@ import { LogItemInterface } from '.'; import { LogAttributes } from '../types'; class LogItem implements LogItemInterface { - private attributes: LogAttributes = {}; - public constructor(params: { baseAttributes: LogAttributes; persistentAttributes: LogAttributes }) { + public constructor(params: { + baseAttributes: LogAttributes; + persistentAttributes: LogAttributes; + }) { // Add attributes in the log item in this order: // - Base attributes supported by the Powertool by default // - Persistent attributes provided by developer, not formatted @@ -32,20 +34,21 @@ class LogItem implements LogItemInterface { public removeEmptyKeys(attributes: LogAttributes): LogAttributes { const newAttributes: LogAttributes = {}; for (const key in attributes) { - if (attributes[key] !== undefined && attributes[key] !== '' && attributes[key] !== null) { + if ( + attributes[key] !== undefined && + attributes[key] !== '' && + attributes[key] !== null + ) { newAttributes[key] = attributes[key]; } } - + return newAttributes; } public setAttributes(attributes: LogAttributes): void { this.attributes = attributes; } - } -export { - LogItem, -}; \ No newline at end of file +export { LogItem }; diff --git a/packages/logger/src/log/LogItemInterface.ts b/packages/logger/src/log/LogItemInterface.ts index debb7038af..cb6113b9d5 100644 --- a/packages/logger/src/log/LogItemInterface.ts +++ b/packages/logger/src/log/LogItemInterface.ts @@ -1,13 +1,9 @@ import { LogAttributes } from '../types'; interface LogItemInterface { + addAttributes(attributes: LogAttributes): void; - addAttributes(attributes: LogAttributes): void - - getAttributes(): LogAttributes - + getAttributes(): LogAttributes; } -export { - LogItemInterface, -}; \ No newline at end of file +export { LogItemInterface }; diff --git a/packages/logger/src/log/index.ts b/packages/logger/src/log/index.ts index 4491038de9..6a3bee0c47 100644 --- a/packages/logger/src/log/index.ts +++ b/packages/logger/src/log/index.ts @@ -1,2 +1,2 @@ export * from './LogItem'; -export * from './LogItemInterface'; \ No newline at end of file +export * from './LogItemInterface'; diff --git a/packages/logger/src/middleware/index.ts b/packages/logger/src/middleware/index.ts index fcc794fc08..cfe9900b37 100644 --- a/packages/logger/src/middleware/index.ts +++ b/packages/logger/src/middleware/index.ts @@ -1 +1 @@ -export * from './middy'; \ No newline at end of file +export * from './middy'; diff --git a/packages/logger/src/middleware/middy.ts b/packages/logger/src/middleware/middy.ts index 9b0140a76f..99c21aa25e 100644 --- a/packages/logger/src/middleware/middy.ts +++ b/packages/logger/src/middleware/middy.ts @@ -2,14 +2,14 @@ import { Logger } from '../Logger'; import { HandlerOptions, LogAttributes } from '../types'; import type { MiddlewareLikeObj, - MiddyLikeRequest + MiddyLikeRequest, } from '@aws-lambda-powertools/commons'; /** * A middy middleware that helps emitting CloudWatch EMF metrics in your logs. * * Using this middleware on your handler function will automatically add context information to logs, as well as optionally log the event and clear attributes set during the invocation. - * + * * @example * ```typescript * import { Logger, injectLambdaContext } from '@aws-lambda-powertools/logger'; @@ -29,24 +29,39 @@ import type { * @param options - (_optional_) Options for the middleware * @returns - The middy middleware object */ -const injectLambdaContext = (target: Logger | Logger[], options?: HandlerOptions): MiddlewareLikeObj => { - +const injectLambdaContext = ( + target: Logger | Logger[], + options?: HandlerOptions +): MiddlewareLikeObj => { const loggers = target instanceof Array ? target : [target]; const persistentAttributes: LogAttributes[] = []; - const injectLambdaContextBefore = async (request: MiddyLikeRequest): Promise => { + const injectLambdaContextBefore = async ( + request: MiddyLikeRequest + ): Promise => { loggers.forEach((logger: Logger, index: number) => { if (options && options.clearState === true) { - persistentAttributes[index] = ({ ...logger.getPersistentLogAttributes() }); + persistentAttributes[index] = { + ...logger.getPersistentLogAttributes(), + }; } - Logger.injectLambdaContextBefore(logger, request.event, request.context, options); + Logger.injectLambdaContextBefore( + logger, + request.event, + request.context, + options + ); }); }; const injectLambdaContextAfterOrOnError = async (): Promise => { if (options && options.clearState === true) { loggers.forEach((logger: Logger, index: number) => { - Logger.injectLambdaContextAfterOrOnError(logger, persistentAttributes[index], options); + Logger.injectLambdaContextAfterOrOnError( + logger, + persistentAttributes[index], + options + ); }); } }; @@ -54,10 +69,8 @@ const injectLambdaContext = (target: Logger | Logger[], options?: HandlerOptions return { before: injectLambdaContextBefore, after: injectLambdaContextAfterOrOnError, - onError: injectLambdaContextAfterOrOnError + onError: injectLambdaContextAfterOrOnError, }; }; -export { - injectLambdaContext, -}; \ No newline at end of file +export { injectLambdaContext }; diff --git a/packages/logger/src/types/Log.ts b/packages/logger/src/types/Log.ts index fe23883631..931ef10027 100644 --- a/packages/logger/src/types/Log.ts +++ b/packages/logger/src/types/Log.ts @@ -6,18 +6,18 @@ type LogLevelSilent = 'SILENT'; type LogLevelCritical = 'CRITICAL'; type LogLevel = - LogLevelDebug | - Lowercase | - LogLevelInfo | - Lowercase | - LogLevelWarn | - Lowercase | - LogLevelError | - Lowercase | - LogLevelSilent | - Lowercase | - LogLevelCritical | - Lowercase; + | LogLevelDebug + | Lowercase + | LogLevelInfo + | Lowercase + | LogLevelWarn + | Lowercase + | LogLevelError + | Lowercase + | LogLevelSilent + | Lowercase + | LogLevelCritical + | Lowercase; type LogLevelThresholds = { [key in Uppercase]: number; @@ -27,7 +27,7 @@ type LogAttributeValue = unknown; type LogAttributes = { [key: string]: LogAttributeValue }; type LogAttributesWithMessage = LogAttributes & { - message: string + message: string; }; type Environment = 'dev' | 'local' | 'staging' | 'prod' | string; @@ -39,4 +39,4 @@ export type { LogLevelThresholds, LogAttributes, LogLevel, -}; \ No newline at end of file +}; diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index 0e3fb113c3..d5d464fe17 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -1,4 +1,8 @@ -import { AsyncHandler, LambdaInterface, SyncHandler } from '@aws-lambda-powertools/commons'; +import { + AsyncHandler, + LambdaInterface, + SyncHandler, +} from '@aws-lambda-powertools/commons'; import { Handler } from 'aws-lambda'; import { ConfigServiceInterface } from '../config'; import { LogFormatterInterface } from '../formatter'; @@ -10,53 +14,56 @@ import { } from './Log'; type ClassThatLogs = { - [key in Exclude, 'silent'>]: (input: LogItemMessage, ...extraInput: LogItemExtraInput) => void; + [key in Exclude, 'silent'>]: ( + input: LogItemMessage, + ...extraInput: LogItemExtraInput + ) => void; }; type HandlerOptions = { - logEvent?: boolean - clearState?: boolean + logEvent?: boolean; + clearState?: boolean; }; type ConstructorOptions = { - logLevel?: LogLevel - serviceName?: string - sampleRateValue?: number - logFormatter?: LogFormatterInterface - customConfigService?: ConfigServiceInterface - persistentLogAttributes?: LogAttributes - environment?: Environment + logLevel?: LogLevel; + serviceName?: string; + sampleRateValue?: number; + logFormatter?: LogFormatterInterface; + customConfigService?: ConfigServiceInterface; + persistentLogAttributes?: LogAttributes; + environment?: Environment; }; type LambdaFunctionContext = { - functionName: string - memoryLimitInMB: number - functionVersion: string - coldStart: boolean - invokedFunctionArn: string - awsRequestId: string + functionName: string; + memoryLimitInMB: number; + functionVersion: string; + coldStart: boolean; + invokedFunctionArn: string; + awsRequestId: string; }; type PowertoolLogData = LogAttributes & { - environment?: Environment - serviceName: string - sampleRateValue?: number - lambdaFunctionContext: LambdaFunctionContext - xRayTraceId?: string - awsRegion: string + environment?: Environment; + serviceName: string; + sampleRateValue?: number; + lambdaFunctionContext: LambdaFunctionContext; + xRayTraceId?: string; + awsRegion: string; }; type UnformattedAttributes = { - environment?: Environment - error?: Error - serviceName: string - sampleRateValue?: number - lambdaContext?: LambdaFunctionContext - xRayTraceId?: string - awsRegion: string - logLevel: LogLevel - timestamp: Date - message: string + environment?: Environment; + error?: Error; + serviceName: string; + sampleRateValue?: number; + lambdaContext?: LambdaFunctionContext; + xRayTraceId?: string; + awsRegion: string; + logLevel: LogLevel; + timestamp: Date; + message: string; }; type LogItemMessage = string | LogAttributesWithMessage; @@ -65,7 +72,9 @@ type LogItemExtraInput = [Error | string] | LogAttributes[]; type HandlerMethodDecorator = ( target: LambdaInterface, propertyKey: string | symbol, - descriptor: TypedPropertyDescriptor> | TypedPropertyDescriptor> + descriptor: + | TypedPropertyDescriptor> + | TypedPropertyDescriptor> ) => void; export { @@ -77,7 +86,7 @@ export { UnformattedAttributes, PowertoolLogData, ConstructorOptions, - HandlerOptions + HandlerOptions, }; export const enum LogJsonIndent { diff --git a/packages/logger/src/types/formats/PowertoolLog.ts b/packages/logger/src/types/formats/PowertoolLog.ts index f3529a684f..add42d298c 100644 --- a/packages/logger/src/types/formats/PowertoolLog.ts +++ b/packages/logger/src/types/formats/PowertoolLog.ts @@ -1,14 +1,13 @@ import type { LogAttributes, LogLevel } from '..'; type PowertoolLog = LogAttributes & { - /** * timestamp * * Description: Timestamp of actual log statement. * Example: "2020-05-24 18:17:33,774" */ - timestamp?: string + timestamp?: string; /** * level @@ -16,7 +15,7 @@ type PowertoolLog = LogAttributes & { * Description: Logging level * Example: "INFO" */ - level?: LogLevel + level?: LogLevel; /** * service @@ -24,7 +23,7 @@ type PowertoolLog = LogAttributes & { * Description: Service name defined. * Example: "payment" */ - service: string + service: string; /** * sampling_rate @@ -32,7 +31,7 @@ type PowertoolLog = LogAttributes & { * Description: The value of the logging sampling rate in percentage. * Example: 0.1 */ - sampling_rate?: number + sampling_rate?: number; /** * message @@ -40,7 +39,7 @@ type PowertoolLog = LogAttributes & { * Description: Log statement value. Unserializable JSON values will be cast to string. * Example: "Collecting payment" */ - message?: string + message?: string; /** * xray_trace_id @@ -48,7 +47,7 @@ type PowertoolLog = LogAttributes & { * Description: X-Ray Trace ID when Lambda function has enabled Tracing. * Example: "1-5759e988-bd862e3fe1be46a994272793" */ - xray_trace_id?: string + xray_trace_id?: string; /** * cold_start @@ -56,7 +55,7 @@ type PowertoolLog = LogAttributes & { * Description: Indicates whether the current execution experienced a cold start. * Example: false */ - cold_start?: boolean + cold_start?: boolean; /** * lambda_function_name @@ -64,7 +63,7 @@ type PowertoolLog = LogAttributes & { * Description: The name of the Lambda function. * Example: "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" */ - lambda_function_name?: string + lambda_function_name?: string; /** * lambda_function_memory_size @@ -72,7 +71,7 @@ type PowertoolLog = LogAttributes & { * Description: The memory size of the Lambda function. * Example: 128 */ - lambda_function_memory_size?: number + lambda_function_memory_size?: number; /** * lambda_function_arn @@ -80,7 +79,7 @@ type PowertoolLog = LogAttributes & { * Description: The ARN of the Lambda function. * Example: "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" */ - lambda_function_arn?: string + lambda_function_arn?: string; /** * lambda_request_id @@ -88,10 +87,7 @@ type PowertoolLog = LogAttributes & { * Description: The request ID of the current invocation. * Example: "899856cb-83d1-40d7-8611-9e78f15f32f4" */ - lambda_request_id?: string - + lambda_request_id?: string; }; -export type { - PowertoolLog -}; \ No newline at end of file +export type { PowertoolLog }; diff --git a/packages/logger/src/types/formats/index.ts b/packages/logger/src/types/formats/index.ts index e5a9bfb5c5..5462610cd6 100644 --- a/packages/logger/src/types/formats/index.ts +++ b/packages/logger/src/types/formats/index.ts @@ -1 +1 @@ -export * from './PowertoolLog'; \ No newline at end of file +export * from './PowertoolLog'; diff --git a/packages/logger/src/types/index.ts b/packages/logger/src/types/index.ts index 3b4ef64069..dc74795384 100644 --- a/packages/logger/src/types/index.ts +++ b/packages/logger/src/types/index.ts @@ -1,2 +1,2 @@ export * from './Log'; -export * from './Logger'; \ No newline at end of file +export * from './Logger'; diff --git a/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts b/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts index 116424e395..6be9c265cb 100644 --- a/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts +++ b/packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts @@ -9,10 +9,14 @@ const REMOVABLE_KEY = process.env.REMOVABLE_KEY || 'removableKey'; const REMOVABLE_VALUE = process.env.REMOVABLE_VALUE || 'remvovableValue'; const ERROR_MSG = process.env.ERROR_MSG || 'error'; const RUNTIME_ADDED_KEY = process.env.RUNTIME_ADDED_KEY || 'runtimeAddedKey'; -const SINGLE_LOG_ITEM_KEY = process.env.SINGLE_LOG_ITEM_KEY || 'keyForSingleLogItem'; -const SINGLE_LOG_ITEM_VALUE = process.env.SINGLE_LOG_ITEM_VALUE || 'valueForSingleLogItem'; -const ARBITRARY_OBJECT_KEY = process.env.ARBITRARY_OBJECT_KEY || 'keyForArbitraryObject'; -const ARBITRARY_OBJECT_DATA = process.env.ARBITRARY_OBJECT_DATA || 'arbitrary object data'; +const SINGLE_LOG_ITEM_KEY = + process.env.SINGLE_LOG_ITEM_KEY || 'keyForSingleLogItem'; +const SINGLE_LOG_ITEM_VALUE = + process.env.SINGLE_LOG_ITEM_VALUE || 'valueForSingleLogItem'; +const ARBITRARY_OBJECT_KEY = + process.env.ARBITRARY_OBJECT_KEY || 'keyForArbitraryObject'; +const ARBITRARY_OBJECT_DATA = + process.env.ARBITRARY_OBJECT_DATA || 'arbitrary object data'; const logger = new Logger({ persistentLogAttributes: { @@ -26,10 +30,11 @@ const testFunction = async (event: TestEvent, context: Context): TestOutput => { // Test feature 2: Event log (this log should have the event data) // Test feature 3: Log level filtering (log level is set to INFO) logger.debug('##### This should not appear'); - + // Test feature 4: Add and remove persistent additional log keys and value logger.removeKeys([REMOVABLE_KEY]); // This key should not appear in any log (except the event log) - logger.appendKeys({ // This key-value pair should appear in every log (except the event log) + logger.appendKeys({ + // This key-value pair should appear in every log (except the event log) [RUNTIME_ADDED_KEY]: event.invocation, }); @@ -50,12 +55,14 @@ const testFunction = async (event: TestEvent, context: Context): TestOutput => { principalId: ARBITRARY_OBJECT_DATA, policyDocument: { Version: 'Version 1', - Statement: [{ - Effect: 'Allow', - Action: 'geo:*', - Resource: '*', - }] - } + Statement: [ + { + Effect: 'Allow', + Action: 'geo:*', + Resource: '*', + }, + ], + }, }; logger.info('A log entry with an object', { [ARBITRARY_OBJECT_KEY]: obj }); @@ -66,5 +73,6 @@ const testFunction = async (event: TestEvent, context: Context): TestOutput => { }; }; -export const handler = middy(testFunction) - .use(injectLambdaContext(logger, { clearState: true, logEvent: 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 04757def04..82a849f6b5 100644 --- a/packages/logger/tests/e2e/basicFeatures.middy.test.ts +++ b/packages/logger/tests/e2e/basicFeatures.middy.test.ts @@ -11,10 +11,13 @@ import { createStackWithLambdaFunction, generateUniqueName, invokeFunction, - isValidRuntimeKey + isValidRuntimeKey, } from '../../../commons/tests/utils/e2eUtils'; import { InvocationLogs } from '../../../commons/tests/utils/InvocationLogs'; -import { deployStack, destroyStack } from '../../../commons/tests/utils/cdk-cli'; +import { + deployStack, + destroyStack, +} from '../../../commons/tests/utils/cdk-cli'; import { RESOURCE_NAME_PREFIX, STACK_OUTPUT_LOG_GROUP, @@ -33,8 +36,18 @@ if (!isValidRuntimeKey(runtime)) { const LEVEL = InvocationLogs.LEVEL; const uuid = v4(); -const stackName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'BasicFeatures-Middy'); -const functionName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'BasicFeatures-Middy'); +const stackName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'BasicFeatures-Middy' +); +const functionName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'BasicFeatures-Middy' +); const lambdaFunctionCodeFile = 'basicFeatures.middy.test.FunctionCode.ts'; const invocationCount = 3; @@ -56,7 +69,6 @@ let logGroupName: string; // We do not know it until deployment let stack: Stack; describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime}`, () => { - let invocationLogs: InvocationLogs[]; beforeAll(async () => { @@ -91,260 +103,277 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime} logGroupName = result.outputs[STACK_OUTPUT_LOG_GROUP]; // Invoke the function three time (one for cold start, then two for warm start) - invocationLogs = await invokeFunction(functionName, invocationCount, 'SEQUENTIAL'); + invocationLogs = await invokeFunction( + functionName, + invocationCount, + 'SEQUENTIAL' + ); console.log('logGroupName', logGroupName); - }, SETUP_TIMEOUT); describe('Log level filtering', () => { - - it('should filter log based on LOG_LEVEL (INFO) environment variable in Lambda', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation and filter by level - const debugLogs = invocationLogs[i].getFunctionLogs(LEVEL.DEBUG); - // Check that no log message below INFO level is logged - expect(debugLogs.length).toBe(0); - } - - }, TEST_CASE_TIMEOUT); + it( + 'should filter log based on LOG_LEVEL (INFO) environment variable in Lambda', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation and filter by level + const debugLogs = invocationLogs[i].getFunctionLogs(LEVEL.DEBUG); + // Check that no log message below INFO level is logged + expect(debugLogs.length).toBe(0); + } + }, + TEST_CASE_TIMEOUT + ); }); describe('Context data', () => { - - it('should inject context info in each log', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - // Check that the context is logged on every log - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - expect(log).toHaveProperty('function_arn'); - expect(log).toHaveProperty('function_memory_size'); - expect(log).toHaveProperty('function_name'); - expect(log).toHaveProperty('function_request_id'); - expect(log).toHaveProperty('timestamp'); + it( + 'should inject context info in each log', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + // Check that the context is logged on every log + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + expect(log).toHaveProperty('function_arn'); + expect(log).toHaveProperty('function_memory_size'); + expect(log).toHaveProperty('function_name'); + expect(log).toHaveProperty('function_request_id'); + expect(log).toHaveProperty('timestamp'); + } } - } - - }, TEST_CASE_TIMEOUT); - - it('should include coldStart equal to TRUE only on the first invocation, FALSE otherwise', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - // Check that cold start is logged correctly on every log - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - if (i === 0) { - expect(log.cold_start).toBe(true); - } else { - expect(log.cold_start).toBe(false); + }, + TEST_CASE_TIMEOUT + ); + + it( + 'should include coldStart equal to TRUE only on the first invocation, FALSE otherwise', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + // Check that cold start is logged correctly on every log + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + if (i === 0) { + expect(log.cold_start).toBe(true); + } else { + expect(log.cold_start).toBe(false); + } } } - } - - }, TEST_CASE_TIMEOUT); - + }, + TEST_CASE_TIMEOUT + ); }); describe('Log event', () => { - - it('should log the event as the first log of each invocation only', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - for (const [ index, message ] of logMessages.entries()) { - const log = InvocationLogs.parseFunctionLog(message); - // Check that the event is logged on the first log - if (index === 0) { - expect(log).toHaveProperty('event'); - expect(log.event).toStrictEqual( - expect.objectContaining({ invocation: i }) - ); - // Check that the event is not logged again on the rest of the logs - } else { - expect(log).not.toHaveProperty('event'); + it( + 'should log the event as the first log of each invocation only', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + for (const [index, message] of logMessages.entries()) { + const log = InvocationLogs.parseFunctionLog(message); + // Check that the event is logged on the first log + if (index === 0) { + expect(log).toHaveProperty('event'); + expect(log.event).toStrictEqual( + expect.objectContaining({ invocation: i }) + ); + // Check that the event is not logged again on the rest of the logs + } else { + expect(log).not.toHaveProperty('event'); + } } } - } - - }, TEST_CASE_TIMEOUT); - + }, + TEST_CASE_TIMEOUT + ); }); describe('Persistent additional log keys and values', () => { - - it('should contain persistent value in every log', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - // Check that the persistent key is present in every log - expect(log).toHaveProperty(PERSISTENT_KEY); - expect(log[PERSISTENT_KEY]).toBe(PERSISTENT_VALUE); + it( + 'should contain persistent value in every log', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + // Check that the persistent key is present in every log + expect(log).toHaveProperty(PERSISTENT_KEY); + expect(log[PERSISTENT_KEY]).toBe(PERSISTENT_VALUE); + } } - } - - }, TEST_CASE_TIMEOUT); - - it('should not contain persistent keys that were removed on runtime', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - for (const [ index, message ] of logMessages.entries()) { - const log = InvocationLogs.parseFunctionLog(message); - // Check that at the time of logging the event, which happens before the handler, - // the key was still present - if (index === 0) { - expect(log).toHaveProperty(REMOVABLE_KEY); - expect(log[REMOVABLE_KEY]).toBe(REMOVABLE_VALUE); - // Check that all other logs that happen at runtime do not contain the key - } else { - expect(log).not.toHaveProperty(REMOVABLE_KEY); + }, + TEST_CASE_TIMEOUT + ); + + it( + 'should not contain persistent keys that were removed on runtime', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + for (const [index, message] of logMessages.entries()) { + const log = InvocationLogs.parseFunctionLog(message); + // Check that at the time of logging the event, which happens before the handler, + // the key was still present + if (index === 0) { + expect(log).toHaveProperty(REMOVABLE_KEY); + expect(log[REMOVABLE_KEY]).toBe(REMOVABLE_VALUE); + // Check that all other logs that happen at runtime do not contain the key + } else { + expect(log).not.toHaveProperty(REMOVABLE_KEY); + } } } - } - - }, TEST_CASE_TIMEOUT); - - it('should not leak any persistent keys added runtime since clearState is enabled', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - for (const [ index, message ] of logMessages.entries()) { - const log = InvocationLogs.parseFunctionLog(message); - // Check that at the time of logging the event, which happens before the handler, - // the key is NOT present - if (index === 0) { - expect(log).not.toHaveProperty(RUNTIME_ADDED_KEY); - } else { - // Check that all other logs that happen at runtime do contain the key - expect(log).toHaveProperty(RUNTIME_ADDED_KEY); - // Check that the value is the same for all logs (it should be the index of the invocation) - expect(log[RUNTIME_ADDED_KEY]).toEqual(i); + }, + TEST_CASE_TIMEOUT + ); + + it( + 'should not leak any persistent keys added runtime since clearState is enabled', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + for (const [index, message] of logMessages.entries()) { + const log = InvocationLogs.parseFunctionLog(message); + // Check that at the time of logging the event, which happens before the handler, + // the key is NOT present + if (index === 0) { + expect(log).not.toHaveProperty(RUNTIME_ADDED_KEY); + } else { + // Check that all other logs that happen at runtime do contain the key + expect(log).toHaveProperty(RUNTIME_ADDED_KEY); + // Check that the value is the same for all logs (it should be the index of the invocation) + expect(log[RUNTIME_ADDED_KEY]).toEqual(i); + } } } - } - - }, TEST_CASE_TIMEOUT); + }, + TEST_CASE_TIMEOUT + ); }); describe('One-time additional log keys and values', () => { - - it('should log additional keys and value only once', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - // Check that the additional log is logged only once - const logMessagesWithAdditionalLog = logMessages.filter( - log => log.includes(SINGLE_LOG_ITEM_KEY) - ); - expect(logMessagesWithAdditionalLog).toHaveLength(1); - // Check that the additional log is logged correctly - const parsedLog = InvocationLogs - .parseFunctionLog(logMessagesWithAdditionalLog[0]); - expect(parsedLog[SINGLE_LOG_ITEM_KEY]).toBe(SINGLE_LOG_ITEM_VALUE); - } - - }, TEST_CASE_TIMEOUT); - + it( + 'should log additional keys and value only once', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + // Check that the additional log is logged only once + const logMessagesWithAdditionalLog = logMessages.filter((log) => + log.includes(SINGLE_LOG_ITEM_KEY) + ); + expect(logMessagesWithAdditionalLog).toHaveLength(1); + // Check that the additional log is logged correctly + const parsedLog = InvocationLogs.parseFunctionLog( + logMessagesWithAdditionalLog[0] + ); + expect(parsedLog[SINGLE_LOG_ITEM_KEY]).toBe(SINGLE_LOG_ITEM_VALUE); + } + }, + TEST_CASE_TIMEOUT + ); }); describe('Error logging', () => { - - it('should log error only once', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation filtered by error level - const logMessages = invocationLogs[i].getFunctionLogs(LEVEL.ERROR); - - // Check that the error is logged only once - expect(logMessages).toHaveLength(1); - - // Check that the error is logged correctly - const errorLog = InvocationLogs.parseFunctionLog(logMessages[0]); - expect(errorLog).toHaveProperty('error'); - expect(errorLog.error).toStrictEqual( - expect.objectContaining({ - location: expect.any(String), - name: 'Error', - message: ERROR_MSG, - stack: expect.anything() - }) - ); - - } - - }, TEST_CASE_TIMEOUT); - + it( + 'should log error only once', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation filtered by error level + const logMessages = invocationLogs[i].getFunctionLogs(LEVEL.ERROR); + + // Check that the error is logged only once + expect(logMessages).toHaveLength(1); + + // Check that the error is logged correctly + const errorLog = InvocationLogs.parseFunctionLog(logMessages[0]); + expect(errorLog).toHaveProperty('error'); + expect(errorLog.error).toStrictEqual( + expect.objectContaining({ + location: expect.any(String), + name: 'Error', + message: ERROR_MSG, + stack: expect.anything(), + }) + ); + } + }, + TEST_CASE_TIMEOUT + ); }); describe('Arbitrary object logging', () => { - - it('should log additional arbitrary object only once', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - // Get the log messages that contains the arbitrary object - const filteredLogs = logMessages - .filter(log => log.includes(ARBITRARY_OBJECT_DATA)); - // Check that the arbitrary object is logged only once - expect(filteredLogs).toHaveLength(1); - const logObject = InvocationLogs.parseFunctionLog(filteredLogs[0]); - // Check that the arbitrary object is logged correctly - expect(logObject).toHaveProperty(ARBITRARY_OBJECT_KEY); - const arbitrary = logObject[ARBITRARY_OBJECT_KEY] as APIGatewayAuthorizerResult; - expect(arbitrary.principalId).toBe(ARBITRARY_OBJECT_DATA); - expect(arbitrary.policyDocument).toEqual(expect.objectContaining( - { - Version: 'Version 1', - Statement: [{ - Effect: 'Allow', - Action: 'geo:*', - Resource: '*' - }] - } - )); - } - - }, TEST_CASE_TIMEOUT); + it( + 'should log additional arbitrary object only once', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + // Get the log messages that contains the arbitrary object + const filteredLogs = logMessages.filter((log) => + log.includes(ARBITRARY_OBJECT_DATA) + ); + // Check that the arbitrary object is logged only once + expect(filteredLogs).toHaveLength(1); + const logObject = InvocationLogs.parseFunctionLog(filteredLogs[0]); + // Check that the arbitrary object is logged correctly + expect(logObject).toHaveProperty(ARBITRARY_OBJECT_KEY); + const arbitrary = logObject[ + ARBITRARY_OBJECT_KEY + ] as APIGatewayAuthorizerResult; + expect(arbitrary.principalId).toBe(ARBITRARY_OBJECT_DATA); + expect(arbitrary.policyDocument).toEqual( + expect.objectContaining({ + Version: 'Version 1', + Statement: [ + { + Effect: 'Allow', + Action: 'geo:*', + Resource: '*', + }, + ], + }) + ); + } + }, + TEST_CASE_TIMEOUT + ); }); describe('X-Ray Trace ID injection', () => { - - it('should inject & parse the X-Ray Trace ID of the current invocation into every log', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - // Check that the X-Ray Trace ID is logged on every log - const traceIds: string[] = []; - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - expect(log).toHaveProperty('xray_trace_id'); - expect(log.xray_trace_id).toMatch(XRAY_TRACE_ID_REGEX); - traceIds.push(log.xray_trace_id as string); + it( + 'should inject & parse the X-Ray Trace ID of the current invocation into every log', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + // Check that the X-Ray Trace ID is logged on every log + const traceIds: string[] = []; + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + expect(log).toHaveProperty('xray_trace_id'); + expect(log.xray_trace_id).toMatch(XRAY_TRACE_ID_REGEX); + traceIds.push(log.xray_trace_id as string); + } } - } - - }, TEST_CASE_TIMEOUT); - + }, + TEST_CASE_TIMEOUT + ); }); afterAll(async () => { diff --git a/packages/logger/tests/e2e/childLogger.manual.test.FunctionCode.ts b/packages/logger/tests/e2e/childLogger.manual.test.FunctionCode.ts index c4e0fd8ec3..f2d32e36f0 100644 --- a/packages/logger/tests/e2e/childLogger.manual.test.FunctionCode.ts +++ b/packages/logger/tests/e2e/childLogger.manual.test.FunctionCode.ts @@ -12,7 +12,7 @@ const CHILD_LOG_LEVEL = (process.env.CHILD_LOG_LEVEL || 'warn') as LogLevel; const parentLogger = new Logger({ persistentLogAttributes: { [PERSISTENT_KEY]: PERSISTENT_VALUE, - } + }, }); // Create a child logger @@ -20,9 +20,12 @@ const childLogger = parentLogger.createChild({ logLevel: CHILD_LOG_LEVEL, }); -export const handler = async (_event: TestEvent, context: Context): TestOutput => { +export const handler = async ( + _event: TestEvent, + context: Context +): TestOutput => { parentLogger.addContext(context); - + childLogger.info(CHILD_LOG_MSG); childLogger.error(CHILD_LOG_MSG); parentLogger.info(PARENT_LOG_MSG); diff --git a/packages/logger/tests/e2e/childLogger.manual.test.ts b/packages/logger/tests/e2e/childLogger.manual.test.ts index 1e11d52b0b..642d2292df 100644 --- a/packages/logger/tests/e2e/childLogger.manual.test.ts +++ b/packages/logger/tests/e2e/childLogger.manual.test.ts @@ -10,16 +10,19 @@ import { createStackWithLambdaFunction, generateUniqueName, invokeFunction, - isValidRuntimeKey + isValidRuntimeKey, } from '../../../commons/tests/utils/e2eUtils'; import { InvocationLogs } from '../../../commons/tests/utils/InvocationLogs'; -import { deployStack, destroyStack } from '../../../commons/tests/utils/cdk-cli'; +import { + deployStack, + destroyStack, +} from '../../../commons/tests/utils/cdk-cli'; import { RESOURCE_NAME_PREFIX, STACK_OUTPUT_LOG_GROUP, SETUP_TIMEOUT, TEST_CASE_TIMEOUT, - TEARDOWN_TIMEOUT + TEARDOWN_TIMEOUT, } from './constants'; const runtime: string = process.env.RUNTIME || 'nodejs18x'; @@ -31,8 +34,18 @@ if (!isValidRuntimeKey(runtime)) { const LEVEL = InvocationLogs.LEVEL; const uuid = v4(); -const stackName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'ChildLogger-Manual'); -const functionName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'ChildLogger-Manual'); +const stackName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'ChildLogger-Manual' +); +const functionName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'ChildLogger-Manual' +); const lambdaFunctionCodeFile = 'childLogger.manual.test.FunctionCode.ts'; const invocationCount = 3; @@ -49,11 +62,9 @@ let logGroupName: string; // We do not know it until deployment let stack: Stack; describe(`logger E2E tests child logger functionalities (manual) for runtime: ${runtime}`, () => { - let invocationLogs: InvocationLogs[]; beforeAll(async () => { - // Create and deploy a stack with AWS CDK stack = createStackWithLambdaFunction({ app: integTestApp, @@ -82,85 +93,93 @@ describe(`logger E2E tests child logger functionalities (manual) for runtime: ${ invocationLogs = await invokeFunction(functionName, invocationCount); console.log('logGroupName', logGroupName); - }, SETUP_TIMEOUT); describe('Child logger', () => { - - it('should not log at same level of parent because of its own logLevel', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation and filter by level - const infoLogs = invocationLogs[i].getFunctionLogs(LEVEL.INFO); - - const parentInfoLogs = infoLogs - .filter(message => message.includes(PARENT_LOG_MSG)); - const childInfoLogs = infoLogs - .filter(message => message.includes(CHILD_LOG_MSG)); - - expect(parentInfoLogs).toHaveLength(infoLogs.length); - expect(childInfoLogs).toHaveLength(0); - } - - }, TEST_CASE_TIMEOUT); - - it('should log only level passed to a child', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - // Filter child logs by level - const errorChildLogs = logMessages - .filter( - message => message.includes(LEVEL.ERROR.toString()) && + it( + 'should not log at same level of parent because of its own logLevel', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation and filter by level + const infoLogs = invocationLogs[i].getFunctionLogs(LEVEL.INFO); + + const parentInfoLogs = infoLogs.filter((message) => + message.includes(PARENT_LOG_MSG) + ); + const childInfoLogs = infoLogs.filter((message) => message.includes(CHILD_LOG_MSG) ); - // Check that the child logger only logged once (the other) - // log was filtered out by the child logger because of its logLevel - expect(errorChildLogs).toHaveLength(1); - } - - }, TEST_CASE_TIMEOUT); - - it('should NOT inject context into the child logger', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - // Filter child logs by level - const childLogMessages = logMessages - .filter(message => message.includes(CHILD_LOG_MSG)); - - // Check that the context is not present in any of the child logs - for (const message of childLogMessages) { - const log = InvocationLogs.parseFunctionLog(message); - expect(log).not.toHaveProperty('function_arn'); - expect(log).not.toHaveProperty('function_memory_size'); - expect(log).not.toHaveProperty('function_name'); - expect(log).not.toHaveProperty('function_request_id'); + expect(parentInfoLogs).toHaveLength(infoLogs.length); + expect(childInfoLogs).toHaveLength(0); } - } - - }, TEST_CASE_TIMEOUT); - - it('both logger instances should have the same persistent key/value', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); + }, + TEST_CASE_TIMEOUT + ); + + it( + 'should log only level passed to a child', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + // Filter child logs by level + const errorChildLogs = logMessages.filter( + (message) => + message.includes(LEVEL.ERROR.toString()) && + message.includes(CHILD_LOG_MSG) + ); - // Check that all logs have the persistent key/value - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - expect(log).toHaveProperty(PERSISTENT_KEY); + // Check that the child logger only logged once (the other) + // log was filtered out by the child logger because of its logLevel + expect(errorChildLogs).toHaveLength(1); } - } - - }, TEST_CASE_TIMEOUT); + }, + TEST_CASE_TIMEOUT + ); + + it( + 'should NOT inject context into the child logger', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + // Filter child logs by level + const childLogMessages = logMessages.filter((message) => + message.includes(CHILD_LOG_MSG) + ); + // Check that the context is not present in any of the child logs + for (const message of childLogMessages) { + const log = InvocationLogs.parseFunctionLog(message); + expect(log).not.toHaveProperty('function_arn'); + expect(log).not.toHaveProperty('function_memory_size'); + expect(log).not.toHaveProperty('function_name'); + expect(log).not.toHaveProperty('function_request_id'); + } + } + }, + TEST_CASE_TIMEOUT + ); + + it( + 'both logger instances should have the same persistent key/value', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + // Check that all logs have the persistent key/value + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + expect(log).toHaveProperty(PERSISTENT_KEY); + } + } + }, + TEST_CASE_TIMEOUT + ); }); afterAll(async () => { diff --git a/packages/logger/tests/e2e/constants.ts b/packages/logger/tests/e2e/constants.ts index 25c928e0c1..1c482b8819 100644 --- a/packages/logger/tests/e2e/constants.ts +++ b/packages/logger/tests/e2e/constants.ts @@ -4,4 +4,4 @@ export const TEST_CASE_TIMEOUT = ONE_MINUTE; export const SETUP_TIMEOUT = 5 * ONE_MINUTE; export const TEARDOWN_TIMEOUT = 5 * ONE_MINUTE; export const STACK_OUTPUT_LOG_GROUP = 'LogGroupName'; -export const XRAY_TRACE_ID_REGEX = /^1-[0-9a-f]{8}-[0-9a-f]{24}$/; \ No newline at end of file +export const XRAY_TRACE_ID_REGEX = /^1-[0-9a-f]{8}-[0-9a-f]{24}$/; diff --git a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts index 6fdcd1ec62..3f816ff4e1 100644 --- a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts +++ b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.FunctionCode.ts @@ -5,10 +5,13 @@ import middy from '@middy/core'; const logger = new Logger(); -const testFunction = async (_event: TestEvent, context: Context): TestOutput => ({ +const testFunction = async ( + _event: TestEvent, + context: Context +): TestOutput => ({ requestId: context.awsRequestId, }); export const handler = middy(testFunction) // The event should be logged because POWERTOOLS_LOGGER_LOG_EVENT is set to true - .use(injectLambdaContext(logger)); + .use(injectLambdaContext(logger)); diff --git a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts index fc49c31a8c..0894c9c18e 100644 --- a/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts +++ b/packages/logger/tests/e2e/logEventEnvVarSetting.middy.test.ts @@ -10,16 +10,19 @@ import { createStackWithLambdaFunction, generateUniqueName, invokeFunction, - isValidRuntimeKey + isValidRuntimeKey, } from '../../../commons/tests/utils/e2eUtils'; import { InvocationLogs } from '../../../commons/tests/utils/InvocationLogs'; -import { deployStack, destroyStack } from '../../../commons/tests/utils/cdk-cli'; +import { + deployStack, + destroyStack, +} from '../../../commons/tests/utils/cdk-cli'; import { RESOURCE_NAME_PREFIX, STACK_OUTPUT_LOG_GROUP, SETUP_TIMEOUT, TEST_CASE_TIMEOUT, - TEARDOWN_TIMEOUT + TEARDOWN_TIMEOUT, } from './constants'; const runtime: string = process.env.RUNTIME || 'nodejs18x'; @@ -29,9 +32,20 @@ if (!isValidRuntimeKey(runtime)) { } const uuid = v4(); -const stackName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'LogEventEnvVarSetting-Middy'); -const functionName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'LogEventEnvVarSetting-Middy'); -const lambdaFunctionCodeFile = 'logEventEnvVarSetting.middy.test.FunctionCode.ts'; +const stackName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'LogEventEnvVarSetting-Middy' +); +const functionName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'LogEventEnvVarSetting-Middy' +); +const lambdaFunctionCodeFile = + 'logEventEnvVarSetting.middy.test.FunctionCode.ts'; const invocationCount = 3; @@ -40,7 +54,6 @@ let logGroupName: string; // We do not know it until deployment let stack: Stack; describe(`logger E2E tests log event via env var setting (middy) for runtime: ${runtime}`, () => { - let invocationLogs: InvocationLogs[]; beforeAll(async () => { @@ -66,37 +79,40 @@ describe(`logger E2E tests log event via env var setting (middy) for runtime: ${ logGroupName = result.outputs[STACK_OUTPUT_LOG_GROUP]; // Invoke the function three time (one for cold start, then two for warm start) - invocationLogs = await invokeFunction(functionName, invocationCount, 'SEQUENTIAL'); + invocationLogs = await invokeFunction( + functionName, + invocationCount, + 'SEQUENTIAL' + ); console.log('logGroupName', logGroupName); - }, SETUP_TIMEOUT); describe('Log event', () => { - - it('should log the event as the first log of each invocation only', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - for (const [ index, message ] of logMessages.entries()) { - const log = InvocationLogs.parseFunctionLog(message); - // Check that the event is logged on the first log - if (index === 0) { - expect(log).toHaveProperty('event'); - expect(log.event).toStrictEqual( - expect.objectContaining({ invocation: i }) - ); - // Check that the event is not logged again on the rest of the logs - } else { - expect(log).not.toHaveProperty('event'); + it( + 'should log the event as the first log of each invocation only', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + for (const [index, message] of logMessages.entries()) { + const log = InvocationLogs.parseFunctionLog(message); + // Check that the event is logged on the first log + if (index === 0) { + expect(log).toHaveProperty('event'); + expect(log.event).toStrictEqual( + expect.objectContaining({ invocation: i }) + ); + // Check that the event is not logged again on the rest of the logs + } else { + expect(log).not.toHaveProperty('event'); + } } } - } - - }, TEST_CASE_TIMEOUT); - + }, + TEST_CASE_TIMEOUT + ); }); afterAll(async () => { diff --git a/packages/logger/tests/e2e/sampleRate.decorator.test.FunctionCode.ts b/packages/logger/tests/e2e/sampleRate.decorator.test.FunctionCode.ts index ba4b7f8895..810e739bdf 100644 --- a/packages/logger/tests/e2e/sampleRate.decorator.test.FunctionCode.ts +++ b/packages/logger/tests/e2e/sampleRate.decorator.test.FunctionCode.ts @@ -23,13 +23,13 @@ class Lambda implements LambdaInterface { // @ts-ignore public async handler(event: TestEvent, context: Context): TestOutput { this.printLogInAllLevels(); - + return { requestId: context.awsRequestId, }; } - private printLogInAllLevels() : void { + private printLogInAllLevels(): void { logger.debug(this.logMsg); logger.info(this.logMsg); logger.warn(this.logMsg); @@ -38,4 +38,4 @@ class Lambda implements LambdaInterface { } const myFunction = new Lambda(); -export const handler = myFunction.handler.bind(myFunction); \ No newline at end of file +export const handler = myFunction.handler.bind(myFunction); diff --git a/packages/logger/tests/e2e/sampleRate.decorator.test.ts b/packages/logger/tests/e2e/sampleRate.decorator.test.ts index 1955b20f46..354e4c461d 100644 --- a/packages/logger/tests/e2e/sampleRate.decorator.test.ts +++ b/packages/logger/tests/e2e/sampleRate.decorator.test.ts @@ -10,16 +10,19 @@ import { createStackWithLambdaFunction, generateUniqueName, invokeFunction, - isValidRuntimeKey + isValidRuntimeKey, } from '../../../commons/tests/utils/e2eUtils'; import { InvocationLogs } from '../../../commons/tests/utils/InvocationLogs'; -import { deployStack, destroyStack } from '../../../commons/tests/utils/cdk-cli'; +import { + deployStack, + destroyStack, +} from '../../../commons/tests/utils/cdk-cli'; import { RESOURCE_NAME_PREFIX, STACK_OUTPUT_LOG_GROUP, SETUP_TIMEOUT, TEST_CASE_TIMEOUT, - TEARDOWN_TIMEOUT + TEARDOWN_TIMEOUT, } from './constants'; const runtime: string = process.env.RUNTIME || 'nodejs18x'; @@ -31,8 +34,18 @@ if (!isValidRuntimeKey(runtime)) { const LEVEL = InvocationLogs.LEVEL; const uuid = v4(); -const stackName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'SampleRate-Decorator'); -const functionName = generateUniqueName(RESOURCE_NAME_PREFIX, uuid, runtime, 'SampleRate-Decorator'); +const stackName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'SampleRate-Decorator' +); +const functionName = generateUniqueName( + RESOURCE_NAME_PREFIX, + uuid, + runtime, + 'SampleRate-Decorator' +); const lambdaFunctionCodeFile = 'sampleRate.decorator.test.FunctionCode.ts'; const invocationCount = 20; @@ -47,11 +60,9 @@ let stack: Stack; let logGroupName: string; // We do not know the exact name until deployment describe(`logger E2E tests sample rate and injectLambdaContext() for runtime: nodejs18x`, () => { - let invocationLogs: InvocationLogs[]; beforeAll(async () => { - // Create and deploy a stack with AWS CDK stack = createStackWithLambdaFunction({ app: integTestApp, @@ -76,56 +87,65 @@ describe(`logger E2E tests sample rate and injectLambdaContext() for runtime: no invocationLogs = await invokeFunction(functionName, invocationCount); console.log('logGroupName', logGroupName); - }, SETUP_TIMEOUT); describe('Enabling sample rate', () => { - it('should log all levels based on given sample rate, not just ERROR', async () => { - // Fetch log streams from all invocations - let countSampled = 0; - let countNotSampled = 0; - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(); - - if (logMessages.length === 1 && logMessages[0].includes(LEVEL.ERROR)) { - countNotSampled++; - } else if (logMessages.length === 4) { - countSampled++; - } else { - console.error(`Log group ${logGroupName} contains missing log`); - throw new Error('Sampled log should have either 1 error log or 4 logs of all levels'); + it( + 'should log all levels based on given sample rate, not just ERROR', + async () => { + // Fetch log streams from all invocations + let countSampled = 0; + let countNotSampled = 0; + + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(); + + if ( + logMessages.length === 1 && + logMessages[0].includes(LEVEL.ERROR) + ) { + countNotSampled++; + } else if (logMessages.length === 4) { + countSampled++; + } else { + console.error(`Log group ${logGroupName} contains missing log`); + throw new Error( + 'Sampled log should have either 1 error log or 4 logs of all levels' + ); + } } - } - - // Given that we set rate to 0.5. The chance that we get all invocations sampled - // (or not sampled) is less than 0.5^20 - expect(countSampled).toBeGreaterThan(0); - expect(countNotSampled).toBeGreaterThan(0); - }, TEST_CASE_TIMEOUT); + // Given that we set rate to 0.5. The chance that we get all invocations sampled + // (or not sampled) is less than 0.5^20 + expect(countSampled).toBeGreaterThan(0); + expect(countNotSampled).toBeGreaterThan(0); + }, + TEST_CASE_TIMEOUT + ); }); describe('Decorator injectLambdaContext()', () => { - it('should inject Lambda context into every log emitted', async () => { - - for (let i = 0; i < invocationCount; i++) { - // Get log messages of the invocation - const logMessages = invocationLogs[i].getFunctionLogs(LEVEL.ERROR); - - // Check that the context is logged on every log - for (const message of logMessages) { - const log = InvocationLogs.parseFunctionLog(message); - expect(log).toHaveProperty('function_arn'); - expect(log).toHaveProperty('function_memory_size'); - expect(log).toHaveProperty('function_name'); - expect(log).toHaveProperty('function_request_id'); - expect(log).toHaveProperty('timestamp'); + it( + 'should inject Lambda context into every log emitted', + async () => { + for (let i = 0; i < invocationCount; i++) { + // Get log messages of the invocation + const logMessages = invocationLogs[i].getFunctionLogs(LEVEL.ERROR); + + // Check that the context is logged on every log + for (const message of logMessages) { + const log = InvocationLogs.parseFunctionLog(message); + expect(log).toHaveProperty('function_arn'); + expect(log).toHaveProperty('function_memory_size'); + expect(log).toHaveProperty('function_name'); + expect(log).toHaveProperty('function_request_id'); + expect(log).toHaveProperty('timestamp'); + } } - } - - }, TEST_CASE_TIMEOUT); + }, + TEST_CASE_TIMEOUT + ); }); afterAll(async () => { diff --git a/packages/logger/tests/helpers/populateEnvironmentVariables.ts b/packages/logger/tests/helpers/populateEnvironmentVariables.ts index 604904e073..a08fd0e35f 100644 --- a/packages/logger/tests/helpers/populateEnvironmentVariables.ts +++ b/packages/logger/tests/helpers/populateEnvironmentVariables.ts @@ -1,8 +1,12 @@ // Reserved variables -process.env._X_AMZN_TRACE_ID = 'Root=1-5759e988-bd862e3fe1be46a994272793;Parent=557abcec3ee5a047;Sampled=1'; +process.env._X_AMZN_TRACE_ID = + 'Root=1-5759e988-bd862e3fe1be46a994272793;Parent=557abcec3ee5a047;Sampled=1'; process.env.AWS_LAMBDA_FUNCTION_NAME = 'my-lambda-function'; process.env.AWS_LAMBDA_FUNCTION_MEMORY_SIZE = '128'; -if (process.env.AWS_REGION === undefined && process.env.CDK_DEFAULT_REGION === undefined) { +if ( + process.env.AWS_REGION === undefined && + process.env.CDK_DEFAULT_REGION === undefined +) { process.env.AWS_REGION = 'eu-west-1'; } diff --git a/packages/logger/tests/helpers/types.ts b/packages/logger/tests/helpers/types.ts index 8c7b5dcbdf..982f65d1bf 100644 --- a/packages/logger/tests/helpers/types.ts +++ b/packages/logger/tests/helpers/types.ts @@ -1,5 +1,5 @@ export type TestEvent = { - invocation: number + invocation: number; }; -export type TestOutput = Promise<{requestId: string}>; \ No newline at end of file +export type TestOutput = Promise<{ requestId: string }>; diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index de72d44adf..11bc29e7a0 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -5,24 +5,31 @@ */ import { ContextExamples as dummyContext, - Events as dummyEvent, LambdaInterface + Events as dummyEvent, + LambdaInterface, } from '@aws-lambda-powertools/commons'; import { createLogger, Logger } from '../../src'; import { EnvironmentVariablesService } from '../../src/config'; import { PowertoolLogFormatter } from '../../src/formatter'; -import { ClassThatLogs, LogJsonIndent, ConstructorOptions, LogLevelThresholds } from '../../src/types'; +import { + ClassThatLogs, + LogJsonIndent, + ConstructorOptions, + LogLevelThresholds, +} from '../../src/types'; import { Context } from 'aws-lambda'; import { Console } from 'console'; const mockDate = new Date(1466424490000); const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); -const getConsoleMethod = (method: string): keyof Omit => - method === 'critical' ? - 'error' : - method.toLowerCase() as keyof Omit; +const getConsoleMethod = ( + method: string +): keyof Omit => + method === 'critical' + ? 'error' + : (method.toLowerCase() as keyof Omit); describe('Class: Logger', () => { - const ENVIRONMENT_VARIABLES = process.env; const context = dummyContext.helloworldContext; const event = dummyEvent.Custom.CustomEvent; @@ -34,18 +41,28 @@ describe('Class: Logger', () => { CRITICAL: 24, SILENT: 28, }; - + beforeEach(() => { dateSpy.mockClear(); process.env = { ...ENVIRONMENT_VARIABLES }; }); describe.each([ - [ 'debug', 'DOES', true, 'DOES NOT', false, 'DOES NOT', false, 'DOES NOT', false ], - [ 'info', 'DOES', true, 'DOES', true, 'DOES NOT', false, 'DOES NOT', false ], - [ 'warn', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES NOT', false ], - [ 'error', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES', true ], - [ 'critical', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES', true ], + [ + 'debug', + 'DOES', + true, + 'DOES NOT', + false, + 'DOES NOT', + false, + 'DOES NOT', + false, + ], + ['info', 'DOES', true, 'DOES', true, 'DOES NOT', false, 'DOES NOT', false], + ['warn', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES NOT', false], + ['error', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES', true], + ['critical', 'DOES', true, 'DOES', true, 'DOES', true, 'DOES', true], ])( 'Method: %p', ( @@ -57,20 +74,19 @@ describe('Class: Logger', () => { warnAction, warnPrints, errorAction, - errorPrints, + errorPrints ) => { - const methodOfLogger = method as keyof ClassThatLogs; describe('Feature: log level', () => { - - test('when the Logger\'s log level is DEBUG, it ' + debugAction + ' print to stdout', () => { - + test(`when the level is DEBUG, it ${debugAction} print to stdout`, () => { // Prepare const logger: Logger = createLogger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(method)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(method)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); @@ -78,24 +94,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(debugPrints ? 1 : 0); if (debugPrints) { - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } - }); - test('when the Logger\'s log level is INFO, it ' + infoAction + ' print to stdout', () => { - + test(`when the log level is INFO, it ${infoAction} print to stdout`, () => { // Prepare const logger: Logger = createLogger({ logLevel: 'INFO', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); @@ -103,24 +122,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(infoPrints ? 1 : 0); if (infoPrints) { - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } - }); - test('when the Logger\'s log level is WARN, it ' + warnAction + ' print to stdout', () => { - + test(`when the log level is WARN, it ${warnAction} print to stdout`, () => { // Prepare const logger: Logger = createLogger({ logLevel: 'WARN', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); @@ -128,24 +150,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(warnPrints ? 1 : 0); if (warnPrints) { - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } - }); - test('when the Logger\'s log level is ERROR, it ' + errorAction + ' print to stdout', () => { - + test(`when the log level is ERROR, it ${errorAction} print to stdout`, () => { // Prepare const logger: Logger = createLogger({ logLevel: 'ERROR', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); @@ -153,24 +178,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(errorPrints ? 1 : 0); if (errorPrints) { - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } - }); - test('when the Logger\'s log level is SILENT, it DOES NOT print to stdout', () => { - + test('when the log level is SILENT, it DOES NOT print to stdout', () => { // Prepare const logger: Logger = createLogger({ logLevel: 'SILENT', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); @@ -179,38 +207,42 @@ describe('Class: Logger', () => { expect(consoleSpy).toBeCalledTimes(0); }); - test('when the Logger\'s log level is set through LOG_LEVEL env variable, it DOES print to stdout', () => { - + test('when the log level is set through LOG_LEVEL env variable, it DOES print to stdout', () => { // Prepare process.env.LOG_LEVEL = methodOfLogger.toUpperCase(); const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act logger[methodOfLogger]('foo'); // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); }); describe('Feature: sample rate', () => { - - test('when the Logger\'s log level is higher and the current Lambda invocation IS NOT sampled for logging, it DOES NOT print to stdout', () => { - + test('when the log level is higher and the current Lambda invocation IS NOT sampled for logging, it DOES NOT print to stdout', () => { // Prepare const logger: Logger = createLogger({ logLevel: 'SILENT', sampleRateValue: 0, }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act if (logger[methodOfLogger]) { @@ -221,14 +253,15 @@ describe('Class: Logger', () => { expect(consoleSpy).toBeCalledTimes(0); }); - test('when the Logger\'s log level is higher and the current Lambda invocation IS sampled for logging, it DOES print to stdout', () => { - + test('when the log level is higher and the current Lambda invocation IS sampled for logging, it DOES print to stdout', () => { // Prepare const logger: Logger = createLogger({ logLevel: 'SILENT', sampleRateValue: 1, }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act if (logger[methodOfLogger]) { @@ -237,215 +270,302 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'foo', - sampling_rate: 1, - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'foo', + sampling_rate: 1, + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); - }); describe('Feature: inject context', () => { + test( + 'when the Lambda context is not captured and a string is passed as log message, it should print a valid ' + + method.toUpperCase() + + ' log', + () => { + // Prepare + const logger: Logger = createLogger(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); + + // Act + if (logger[methodOfLogger]) { + logger[methodOfLogger]('foo'); + } - test('when the Lambda context is not captured and a string is passed as log message, it should print a valid ' + method.toUpperCase() + ' log', () => { - - // Prepare - const logger: Logger = createLogger(); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); - - // Act - if (logger[methodOfLogger]) { - logger[methodOfLogger]('foo'); + // Assess + expect(consoleSpy).toBeCalledTimes(1); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } + ); - // Assess - expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'foo', - service: 'hello-world', - 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', () => { - - // Prepare - const logger: Logger & { addContext: (context: Context) => void } = createLogger({ - logLevel: 'DEBUG', - }); - logger.addContext(context); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + test( + 'when the Lambda context is captured, it returns a valid ' + + method.toUpperCase() + + ' log', + () => { + // Prepare + const logger: Logger & { addContext: (context: Context) => void } = + createLogger({ + logLevel: 'DEBUG', + }); + logger.addContext(context); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); + + // Act + if (logger[methodOfLogger]) { + logger[methodOfLogger]('foo'); + } - // Act - if (logger[methodOfLogger]) { - logger[methodOfLogger]('foo'); + // Assess + expect(consoleSpy).toBeCalledTimes(1); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: method.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); } - - // Assess - expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: method.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - - }); - + ); }); describe('Feature: ephemeral log attributes', () => { - test('when added, they should appear in that log item only', () => { - // Prepare const logger: Logger = createLogger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); - - interface NestedObject { bool: boolean; str: string; num: number; err: Error } - interface ArbitraryObject { value: 'CUSTOM' | 'USER_DEFINED'; nested: TNested } + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); + + interface NestedObject { + bool: boolean; + str: string; + num: number; + err: Error; + } + interface ArbitraryObject { + value: 'CUSTOM' | 'USER_DEFINED'; + nested: TNested; + } const arbitraryObject: ArbitraryObject = { value: 'CUSTOM', - nested: { bool: true, str: 'string value', num: 42, err: new Error('Arbitrary object error') } + nested: { + bool: true, + str: 'string value', + num: 42, + err: new Error('Arbitrary object error'), + }, }; // Act if (logger[methodOfLogger]) { logger[methodOfLogger]('A log item without extra parameters'); - logger[methodOfLogger]('A log item with a string as first parameter, and an object as second parameter', { extra: 'parameter' }); - logger[methodOfLogger]('A log item with a string as first parameter, and objects as other parameters', { parameterOne: 'foo' }, { parameterTwo: 'bar' }); - logger[methodOfLogger]({ message: 'A log item with an object as first parameters', extra: 'parameter' }); - logger[methodOfLogger]('A log item with a string as first parameter, and an error as second parameter', new Error('Something happened!')); - logger[methodOfLogger]('A log item with a string as first parameter, and an error with custom key as second parameter', { myCustomErrorKey: new Error('Something happened!') }); - logger[methodOfLogger]('A log item with a string as first parameter, and a string as second parameter', 'parameter'); - logger[methodOfLogger]('A log item with a string as first parameter, and an inline object as second parameter', { extra: { custom: mockDate } }); - logger[methodOfLogger]('A log item with a string as first parameter, and an arbitrary object as second parameter', { extra: arbitraryObject }); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and an object as second parameter', + { extra: 'parameter' } + ); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and objects as other parameters', + { parameterOne: 'foo' }, + { parameterTwo: 'bar' } + ); + logger[methodOfLogger]({ + message: 'A log item with an object as first parameters', + extra: 'parameter', + }); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and an error as second parameter', + new Error('Something happened!') + ); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and an error with custom key as second parameter', + { myCustomErrorKey: new Error('Something happened!') } + ); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and a string as second parameter', + 'parameter' + ); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and an inline object as second parameter', + { extra: { custom: mockDate } } + ); + logger[methodOfLogger]( + 'A log item with a string as first parameter, and an arbitrary object as second parameter', + { extra: arbitraryObject } + ); } // Assess - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item without extra parameters', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(2, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and an object as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - extra: 'parameter', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(3, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and objects as other parameters', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - parameterOne: 'foo', - parameterTwo: 'bar', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(4, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item with an object as first parameters', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - extra: 'parameter', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'A log item without extra parameters', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 2, + JSON.stringify({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and an object as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + extra: 'parameter', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 3, + JSON.stringify({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and objects as other parameters', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + parameterOne: 'foo', + parameterTwo: 'bar', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 4, + JSON.stringify({ + level: method.toUpperCase(), + message: 'A log item with an object as first parameters', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + extra: 'parameter', + }) + ); const parameterCallNumber5 = JSON.parse(consoleSpy.mock.calls[4][0]); - expect(parameterCallNumber5).toEqual(expect.objectContaining({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and an error as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - error: { - location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), - message: 'Something happened!', - name: 'Error', - stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/), - }, - })); - const parameterCallNumber6 = JSON.parse(consoleSpy.mock.calls[5][0] as string); - expect(parameterCallNumber6).toEqual(expect.objectContaining({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and an error with custom key as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - myCustomErrorKey: { - location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), - message: 'Something happened!', - name: 'Error', - stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/), - }, - })); - expect(consoleSpy).toHaveBeenNthCalledWith(7, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and a string as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - extra: 'parameter', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(8, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and an inline object as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - extra: { custom: '2016-06-20T12:08:10.000Z' } - })); + expect(parameterCallNumber5).toEqual( + expect.objectContaining({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and an error as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + error: { + location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), + message: 'Something happened!', + name: 'Error', + stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/), + }, + }) + ); + const parameterCallNumber6 = JSON.parse( + consoleSpy.mock.calls[5][0] as string + ); + expect(parameterCallNumber6).toEqual( + expect.objectContaining({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and an error with custom key as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + myCustomErrorKey: { + location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), + message: 'Something happened!', + name: 'Error', + stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/), + }, + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 7, + JSON.stringify({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and a string as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + extra: 'parameter', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 8, + JSON.stringify({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and an inline object as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + extra: { custom: '2016-06-20T12:08:10.000Z' }, + }) + ); const parameterCallNumber9 = JSON.parse(consoleSpy.mock.calls[8][0]); - expect(parameterCallNumber9).toEqual(expect.objectContaining({ - level: method.toUpperCase(), - message: 'A log item with a string as first parameter, and an arbitrary object as second parameter', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - extra: { - value: 'CUSTOM', - nested: { - bool: true, - str: 'string value', - num: 42, - err: { - location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), - message: 'Arbitrary object error', - name: 'Error', - stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/), - } - } - } - })); - + expect(parameterCallNumber9).toEqual( + expect.objectContaining({ + level: method.toUpperCase(), + message: + 'A log item with a string as first parameter, and an arbitrary object as second parameter', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + extra: { + value: 'CUSTOM', + nested: { + bool: true, + str: 'string value', + num: 42, + err: { + location: expect.stringMatching(/Logger.test.ts:[0-9]+$/), + message: 'Arbitrary object error', + name: 'Error', + stack: expect.stringMatching( + /Logger.test.ts:[0-9]+:[0-9]+/ + ), + }, + }, + }, + }) + ); }); - }); describe('Feature: persistent log attributes', () => { - test('when persistent log attributes are added to the Logger instance, they should appear in all logs printed by the instance', () => { - // Prepare const logger: Logger = createLogger({ logLevel: 'DEBUG', @@ -454,7 +574,9 @@ describe('Class: Logger', () => { aws_region: 'eu-west-1', }, }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act if (logger[methodOfLogger]) { @@ -463,29 +585,30 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - aws_account_id: '123456789012', - aws_region: 'eu-west-1', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + aws_account_id: '123456789012', + aws_region: 'eu-west-1', + }) + ); }); - }); describe('Feature: X-Ray Trace ID injection', () => { - test('when the `_X_AMZN_TRACE_ID` environment variable is set it parses it correctly and adds the Trace ID to the log', () => { - // Prepare const logger: Logger = createLogger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act if (logger[methodOfLogger]) { @@ -494,24 +617,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'foo', + service: 'hello-world', + 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', () => { - // Prepare delete process.env._X_AMZN_TRACE_ID; const logger: Logger = createLogger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); // Act if (logger[methodOfLogger]) { @@ -520,26 +646,27 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'foo', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'foo', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + }) + ); }); - }); describe('Feature: handle safely unexpected errors', () => { - test('when a logged item references itself, the logger ignores the keys that cause a circular reference', () => { - // Prepare const logger: Logger = createLogger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); const circularObject = { foo: 'bar', self: {}, @@ -547,7 +674,9 @@ describe('Class: Logger', () => { circularObject.self = circularObject; const logCircularReference = (): string => { if (logger[methodOfLogger]) { - logger[methodOfLogger]('A log with a circular reference', { details: circularObject }); + logger[methodOfLogger]('A log with a circular reference', { + details: circularObject, + }); } return 'All good!'; @@ -558,88 +687,101 @@ describe('Class: Logger', () => { // Assess expect(result).toBe('All good!'); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: method.toUpperCase(), - message: 'A log with a circular reference', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - details: { - foo: 'bar', - }, - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: method.toUpperCase(), + message: 'A log with a circular reference', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + details: { + foo: 'bar', + }, + }) + ); }); - test('when a logged item has BigInt value, it doesn\'t throw TypeError', () => { - + test('when a logged item has BigInt value, it does not throw TypeError', () => { // Prepare const logger = new Logger(); - jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); const message = `This is an ${methodOfLogger} log with BigInt value`; const logItem = { value: BigInt(42) }; const errorMessage = 'Do not know how to serialize a BigInt'; - + // Act & Assess - expect(() => { logger[methodOfLogger](message, logItem); }).not.toThrow(errorMessage); - + expect(() => { + logger[methodOfLogger](message, logItem); + }).not.toThrow(errorMessage); }); - + test('when a logged item has a BigInt value, it prints the log with value as a string', () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); const message = `This is an ${methodOfLogger} log with BigInt value`; const logItem = { value: BigInt(42) }; - + // Act logger[methodOfLogger](message, logItem); - + // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: message, - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - value: '42', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: message, + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + value: '42', + }) + ); }); test('when a logged item has empty string, null, or undefined values, it removes it', () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], getConsoleMethod(methodOfLogger)).mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) + .mockImplementation(); const message = `This is an ${methodOfLogger} log with empty, null, and undefined values`; - const logItem = { value: 42, emptyValue: '', undefinedValue: undefined, nullValue: null }; - + const logItem = { + value: 42, + emptyValue: '', + undefinedValue: undefined, + nullValue: null, + }; + // Act logger[methodOfLogger](message, logItem); - + // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: methodOfLogger.toUpperCase(), - message: message, - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - value: 42, - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: methodOfLogger.toUpperCase(), + message: message, + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + value: 42, + }) + ); }); - }); - }); + } + ); describe('Method: addContext', () => { - - 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 PowertoolLogData object with coldStart set to TRUE', () => { // Prepare const logger = new Logger(); @@ -658,7 +800,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -670,40 +812,52 @@ describe('Class: Logger', () => { coldStart: true, functionName: 'foo-bar-function', functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + 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 = { ...context, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; - const context2 = { ...context, 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); logger.addContext(context2); // Assess - expect(context1.awsRequestId).toEqual('c6af9ac6-7b61-11e6-9a41-93e812345678'); - expect(context2.awsRequestId).toEqual('d40c98a9-91c4-478c-a179-433c4b978289'); - + 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 = { ...context, awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678' }; - const context2 = { ...context, 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); @@ -715,19 +869,15 @@ describe('Class: Logger', () => { powertoolLogData: expect.objectContaining({ lambdaContext: expect.objectContaining({ awsRequestId: context2.awsRequestId, - }) - }) + }), + }), }) ); - }); - }); describe('Method: appendKeys', () => { - - test('when called, it populates the logger\'s persistentLogAttributes property', () => { - + test('when called, it populates the logger persistentLogAttributes property', () => { // Prepare const logger = new Logger(); @@ -742,21 +892,21 @@ describe('Class: Logger', () => { }); // Assess - expect(logger).toEqual(expect.objectContaining({ - persistentLogAttributes: { - aws_account_id: '123456789012', - aws_region: 'eu-west-1', - logger: { - name: 'aws-lambda-powertool-typescript', - version: '0.2.4', + expect(logger).toEqual( + expect.objectContaining({ + persistentLogAttributes: { + aws_account_id: '123456789012', + aws_region: 'eu-west-1', + logger: { + name: 'aws-lambda-powertool-typescript', + version: '0.2.4', + }, }, - }, - })); - + }) + ); }); test('when called with user-provided attribute objects, the objects are not mutated', () => { - // Prepare const logger = new Logger(); const attributes1 = { keyOne: 'abc' }; @@ -769,37 +919,33 @@ 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', () => { - // Prepare const logger = new Logger(); // Act logger.appendKeys({ - duplicateKey: 'one' + duplicateKey: 'one', }); logger.appendKeys({ - duplicateKey: 'two' + duplicateKey: 'two', }); // Assess - expect(logger).toEqual(expect.objectContaining({ - persistentLogAttributes: { - duplicateKey: 'two' - } - })); - + expect(logger).toEqual( + expect.objectContaining({ + persistentLogAttributes: { + duplicateKey: 'two', + }, + }) + ); }); - }); describe('Method: removeKeys', () => { - - test('when called, it removes keys from the logger\'s persistentLogAttributes property', () => { - + test('when called, it removes keys from the logger persistentLogAttributes property', () => { // Prepare const logger = new Logger(); logger.appendKeys({ @@ -812,22 +958,22 @@ describe('Class: Logger', () => { }); // Act - logger.removeKeys([ 'aws_account_id', 'aws_region' ]); + logger.removeKeys(['aws_account_id', 'aws_region']); // Assess - expect(logger).toEqual(expect.objectContaining({ - persistentLogAttributes: { - logger: { - name: 'aws-lambda-powertool-typescript', - version: '0.2.4', + expect(logger).toEqual( + expect.objectContaining({ + persistentLogAttributes: { + logger: { + name: 'aws-lambda-powertool-typescript', + version: '0.2.4', + }, }, - }, - })); - + }) + ); }); - test('when called with non-existing keys, the logger\'s property persistentLogAttributes is not mutated and it does not throw an error', () => { - + test('when called with non-existing keys, the logger property persistentLogAttributes is not mutated and it does not throw an error', () => { // Prepare const logger = new Logger(); logger.appendKeys({ @@ -845,21 +991,21 @@ describe('Class: Logger', () => { // Assess expect(logger).toEqual(loggerBeforeKeysAreRemoved); - expect(logger).toEqual(expect.objectContaining({ - persistentLogAttributes: { - aws_account_id: '123456789012', - aws_region: 'eu-west-1', - logger: { - name: 'aws-lambda-powertool-typescript', - version: '0.2.4', + expect(logger).toEqual( + expect.objectContaining({ + persistentLogAttributes: { + aws_account_id: '123456789012', + aws_region: 'eu-west-1', + logger: { + name: 'aws-lambda-powertool-typescript', + version: '0.2.4', + }, }, - }, - })); - + }) + ); }); test('when called multiple times with the same keys, the outcome is the same', () => { - // Prepare const logger = new Logger(); logger.appendKeys({ @@ -870,50 +1016,51 @@ describe('Class: Logger', () => { version: '0.2.4', }, }); - + // Act - logger.removeKeys([ 'aws_account_id', 'aws_region' ]); - logger.removeKeys([ 'aws_account_id', 'aws_region' ]); - + logger.removeKeys(['aws_account_id', 'aws_region']); + logger.removeKeys(['aws_account_id', 'aws_region']); + // Assess - expect(logger).toEqual(expect.objectContaining({ - persistentLogAttributes: { - logger: { - name: 'aws-lambda-powertool-typescript', - version: '0.2.4', + expect(logger).toEqual( + expect.objectContaining({ + persistentLogAttributes: { + logger: { + name: 'aws-lambda-powertool-typescript', + version: '0.2.4', + }, }, - }, - })); - + }) + ); }); - }); describe('Method: injectLambdaContext', () => { - beforeEach(() => { jest.spyOn(console, 'log').mockImplementation(() => ({})); }); test('it returns a decorated method with the correct scope of the decorated class', async () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { this.myClassMethod(); } private myClassMethod(): void { logger.info('This is an INFO log with some context'); } - } const handlerClass = new LambdaFunction(); const handler = handlerClass.handler.bind(handlerClass); @@ -923,32 +1070,38 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'This is an INFO log with some context', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'This is an INFO log with some context', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); - test('it captures Lambda\'s context information and adds it in the printed logs', async () => { - + test('it captures Lambda context information and adds it in the printed logs', async () => { // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { logger.info('This is an INFO log with some context'); } } @@ -962,40 +1115,49 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(2); - expect(consoleSpy).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: '1-5759e988-bd862e3fe1be46a994272793', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(2, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'This is an INFO log with some context', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).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: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 2, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'This is an INFO log with some context', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); - test('it captures Lambda\'s context information and adds it in the printed logs for async methods', async () => { - + test('it captures Lambda context information and adds it in the printed logs for async methods', async () => { // Prepare const expectedReturnValue = 'Lambda invoked!'; const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { logger.info('This is an INFO log with some context'); return expectedReturnValue; @@ -1012,48 +1174,55 @@ describe('Class: Logger', () => { expect(actualResult).toEqual(expectedReturnValue); expect(consoleSpy).toBeCalledTimes(2); - expect(consoleSpy).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: '1-5759e988-bd862e3fe1be46a994272793', - })); - expect(consoleSpy).toHaveBeenNthCalledWith(2, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'This is an INFO log with some context', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).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: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); + expect(consoleSpy).toHaveBeenNthCalledWith( + 2, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'This is an INFO log with some context', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); 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({ logLevel: 'DEBUG', persistentLogAttributes: { foo: 'bar', - biz: 'baz' - } + biz: 'baz', + }, }); jest.spyOn(logger['console'], 'debug').mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext({ clearState: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): 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: '1234' } + 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'); @@ -1061,41 +1230,47 @@ describe('Class: Logger', () => { } const handlerClass = new LambdaFunction(); const handler = handlerClass.handler.bind(handlerClass); - const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; + const persistentAttribsBeforeInvocation = { + ...logger.getPersistentLogAttributes(), + }; // Act await handler(event, context); - const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; + const persistentAttribsAfterInvocation = { + ...logger.getPersistentLogAttributes(), + }; // Assess expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', - biz: 'baz' + biz: 'baz', }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); - + expect(persistentAttribsAfterInvocation).toEqual( + persistentAttribsBeforeInvocation + ); }); 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({ logLevel: 'DEBUG', persistentLogAttributes: { foo: 'bar', - biz: 'baz' - } + biz: 'baz', + }, }); jest.spyOn(logger['console'], 'debug').mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext({ clearState: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): 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: '1234' } + 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'); @@ -1105,32 +1280,40 @@ describe('Class: Logger', () => { } const handlerClass = new LambdaFunction(); const handler = handlerClass.handler.bind(handlerClass); - const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; + const persistentAttribsBeforeInvocation = { + ...logger.getPersistentLogAttributes(), + }; // Act & Assess await expect(handler(event, context)).rejects.toThrow(); - const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; + const persistentAttribsAfterInvocation = { + ...logger.getPersistentLogAttributes(), + }; expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', - biz: 'baz' + biz: 'baz', }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); - + expect(persistentAttribsAfterInvocation).toEqual( + persistentAttribsBeforeInvocation + ); }); 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(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext({ logEvent: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { return; } } @@ -1142,41 +1325,47 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'Lambda invocation event', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - event: { - key1: 'value1', - key2: 'value2', - key3: 'value3' - } - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'Lambda invocation event', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + event: { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }, + }) + ); }); 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'; const logger = new Logger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { - @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { return; } } @@ -1188,33 +1377,37 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'Lambda invocation event', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - event: { - key1: 'value1', - key2: 'value2', - key3: 'value3' - } - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'Lambda invocation event', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + event: { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }, + }) + ); }); test('it preserves the value of `this` of the decorated method/class', async () => { - // Prepare const logger = new Logger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { private readonly memberVariable: string; @@ -1226,7 +1419,10 @@ describe('Class: Logger', () => { @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: TEvent, _context: Context): Promise { + public async handler( + _event: TEvent, + _context: Context + ): Promise { this.dummyMethod(); return; @@ -1244,23 +1440,25 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'memberVariable:someValue', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'memberVariable:someValue', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); test('it awaits the decorated method correctly', async () => { - // Prepare const injectLambdaContextAfterOrOnErrorSpy = jest.spyOn( Logger, @@ -1269,12 +1467,17 @@ describe('Class: Logger', () => { const logger = new Logger({ logLevel: 'DEBUG', }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { @logger.injectLambdaContext() // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(_event: unknown, _context: unknown): Promise { + public async handler( + _event: unknown, + _context: unknown + ): Promise { await this.dummyMethod(); logger.info('This is a DEBUG log'); @@ -1293,28 +1496,32 @@ describe('Class: Logger', () => { // Assess expect(consoleSpy).toBeCalledTimes(1); - // Here we assert that the logger.info method is called before the cleanup function that should always + // Here we assert that the logger.info method is called before the cleanup function that should always // be called ONLY after the handler has returned. If logger.info is called after the cleanup function // it means the decorator is NOT awaiting the handler which would cause the test to fail. - expect(consoleSpy.mock.invocationCallOrder[0]) - .toBeLessThan(injectLambdaContextAfterOrOnErrorSpy.mock.invocationCallOrder[0]); - + expect(consoleSpy.mock.invocationCallOrder[0]).toBeLessThan( + injectLambdaContextAfterOrOnErrorSpy.mock.invocationCallOrder[0] + ); }); test('when logEvent and clearState are both TRUE, and the logger has persistent attributes, any key added in the handler is cleared properly', async () => { - // Prepare const logger = new Logger({ persistentLogAttributes: { version: '1.0.0', - } + }, }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); class LambdaFunction implements LambdaInterface { @logger.injectLambdaContext({ clearState: true, logEvent: true }) // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore - public async handler(event: { foo: string }, _context: unknown): Promise { + public async handler( + event: { foo: string }, + _context: unknown + ): Promise { logger.appendKeys({ foo: event.foo }); return; @@ -1334,38 +1541,34 @@ describe('Class: Logger', () => { for (let i = 1; i === 5; i++) { expect(consoleSpy).toHaveBeenNthCalledWith( i, - expect.stringContaining('\"message\":\"Lambda invocation event\"'), + expect.stringContaining('"message":"Lambda invocation event"') ); expect(consoleSpy).toHaveBeenNthCalledWith( i, - expect.stringContaining('\"version\":\"1.0.0\"'), + expect.stringContaining('"version":"1.0.0"') ); } expect(consoleSpy).toHaveBeenNthCalledWith( 2, - expect.not.stringContaining('\"foo\":\"bar\"') + expect.not.stringContaining('"foo":"bar"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 3, - expect.not.stringContaining('\"foo\":\"baz\"') + expect.not.stringContaining('"foo":"baz"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 4, - expect.not.stringContaining('\"foo\":\"biz\"') + expect.not.stringContaining('"foo":"biz"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 5, - expect.not.stringContaining('\"foo\":\"buz\"') + expect.not.stringContaining('"foo":"buz"') ); - }); - }); describe('Method: refreshSampleRateCalculation', () => { - - test('it recalculates whether the current Lambda invocation\'s logs will be printed or not', () => { - + test('it recalculates whether the current Lambda invocation logs will be printed or not', () => { // Prepare const logger = new Logger({ logLevel: 'ERROR', @@ -1384,14 +1587,11 @@ describe('Class: Logger', () => { // Assess expect(logsSampledCount > 50).toBe(true); expect(logsSampledCount < 150).toBe(true); - }); - }); describe('Method: createChild', () => { - - test('child and grandchild loggers should have all ancestor\'s options', () => { + test('child and grandchild loggers should have all the options of its ancestor', () => { // Prepare const INDENTATION = LogJsonIndent.COMPACT; const loggerOptions = { @@ -1399,7 +1599,7 @@ describe('Class: Logger', () => { sampleRateValue: 0, }; const parentLogger = new Logger(loggerOptions); - + // Act const childLoggerOptions = { sampleRateValue: 1 }; const childLogger = parentLogger.createChild(childLoggerOptions); @@ -1423,7 +1623,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -1446,7 +1646,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: true, persistentLogAttributes: {}, @@ -1469,7 +1669,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: true, persistentLogAttributes: {}, @@ -1480,11 +1680,9 @@ describe('Class: Logger', () => { serviceName: 'grandchild-logger-name', }, }); - }); test('child logger should be a DISTINCT clone of the logger instance', () => { - // Prepare const INDENTATION = LogJsonIndent.COMPACT; const parentLogger = new Logger(); @@ -1494,20 +1692,27 @@ describe('Class: Logger', () => { const optionsWithPermanentAttributes = { persistentLogAttributes: { - extra: 'This is an attribute that will be logged only by the child logger', + extra: + 'This is an attribute that will be logged only by the child logger', }, }; - const childLoggerWithPermanentAttributes = parentLogger.createChild(optionsWithPermanentAttributes); + const childLoggerWithPermanentAttributes = parentLogger.createChild( + optionsWithPermanentAttributes + ); const optionsWithSampleRateEnabled = { sampleRateValue: 1, // 100% probability to make sure that the logs are sampled }; - const childLoggerWithSampleRateEnabled = parentLogger.createChild(optionsWithSampleRateEnabled); + const childLoggerWithSampleRateEnabled = parentLogger.createChild( + optionsWithSampleRateEnabled + ); const optionsWithErrorLogLevel: ConstructorOptions = { logLevel: 'ERROR', }; - const childLoggerWithErrorLogLevel = parentLogger.createChild(optionsWithErrorLogLevel); + const childLoggerWithErrorLogLevel = parentLogger.createChild( + optionsWithErrorLogLevel + ); // Assess expect(parentLogger === childLogger).toBe(false); @@ -1530,7 +1735,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -1553,11 +1758,12 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: { - extra: 'This is an attribute that will be logged only by the child logger', + extra: + 'This is an attribute that will be logged only by the child logger', }, powertoolLogData: { awsRegion: 'eu-west-1', @@ -1578,7 +1784,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: true, persistentLogAttributes: {}, @@ -1601,7 +1807,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'ERROR', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -1612,11 +1818,9 @@ describe('Class: Logger', () => { serviceName: 'hello-world', }, }); - }); - test('child logger should have parent\'s keys in persistentLogAttributes', () => { - + test('child logger should have same keys in persistentLogAttributes as its parent', () => { // Prepare const INDENTATION = LogJsonIndent.COMPACT; const parentLogger = new Logger(); @@ -1630,7 +1834,7 @@ describe('Class: Logger', () => { name: 'aws-lambda-powertool-typescript', version: '0.2.4', }, - test_key: 'key-for-test' + test_key: 'key-for-test', }); const childLoggerWithKeys = parentLogger.createChild(); childLoggerWithKeys.removeKeys(['test_key']); @@ -1647,7 +1851,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -1670,7 +1874,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: { @@ -1700,7 +1904,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: { @@ -1719,11 +1923,9 @@ describe('Class: Logger', () => { serviceName: 'hello-world', }, }); - }); - test('child logger should have parent\'s context in PowertoolLogData', () => { - + test('child logger should have same context as its parent', () => { // Prepare const parentLogger = new Logger(); @@ -1743,7 +1945,7 @@ describe('Class: Logger', () => { logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -1755,22 +1957,21 @@ describe('Class: Logger', () => { coldStart: true, functionName: 'foo-bar-function', functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + 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', () => { - + test('child logger should have the same logFormatter as its parent', () => { // Prepare class MyCustomLogFormatter extends PowertoolLogFormatter {} const parentLogger = new Logger({ - logFormatter: new MyCustomLogFormatter() + logFormatter: new MyCustomLogFormatter(), }); // Act @@ -1782,18 +1983,16 @@ describe('Class: Logger', () => { logFormatter: expect.any(MyCustomLogFormatter), }) ); - }); test('child logger with custom logFormatter in options should have provided logFormatter', () => { - // Prepare class MyCustomLogFormatter extends PowertoolLogFormatter {} const parentLogger = new Logger(); // Act const childLoggerWithCustomLogFormatter = parentLogger.createChild({ - logFormatter: new MyCustomLogFormatter() + logFormatter: new MyCustomLogFormatter(), }); // Assess @@ -1808,11 +2007,9 @@ 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', () => { - // Prepare class MyCustomLogFormatter extends PowertoolLogFormatter {} class MyCustomEnvironmentVariablesService extends EnvironmentVariablesService {} @@ -1827,7 +2024,7 @@ describe('Class: Logger', () => { aws_account_id: '1234567890', aws_region: 'eu-west-1', }, - environment: 'local' + environment: 'local', }; const parentLogger = new Logger(options); @@ -1852,108 +2049,113 @@ describe('Class: Logger', () => { customConfigService: expect.any(MyCustomEnvironmentVariablesService), }) ); - }); - }); describe('Method: logEventIfEnabled', () => { - test('When the feature is disabled, it DOES NOT log the event', () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); // Act logger.logEventIfEnabled(event); // Assess expect(consoleSpy).toBeCalledTimes(0); - }); test('When the feature is enabled via overwrite flag, it DOES log the event', () => { - // Prepare const event = { - something: 'happened!' + something: 'happened!', }; const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); // Act logger.logEventIfEnabled(event, true); // Assess 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: '1-5759e988-bd862e3fe1be46a994272793', - event: { - something: 'happened!' - } - }, - )); - + 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: '1-5759e988-bd862e3fe1be46a994272793', + event: { + something: 'happened!', + }, + }) + ); }); }); describe('Feature: Pretty indentation for a local or non-production environment', () => { - test('when the `POWERTOOLS_DEV` env var is SET it makes log output has multiple lines', () => { - // Prepare process.env.POWERTOOLS_DEV = 'true'; const INDENTATION = LogJsonIndent.PRETTY; const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); // Act logger.info('Message with pretty identation'); - + // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: 'INFO', - message: 'Message with pretty identation', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - }, null, INDENTATION)); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify( + { + level: 'INFO', + message: 'Message with pretty identation', + service: 'hello-world', + 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', () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); // Act logger.info('Message without pretty identation'); - + // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - level: 'INFO', - message: 'Message without pretty identation', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + level: 'INFO', + message: 'Message without pretty identation', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); - }); describe('Method: setConsole()', () => { - test('When the `POWERTOOLS_DEV` env var is SET console object is set to the global node console otherwise to the instance of the internal version of console', () => { - // Prepare const logger = new Logger(); process.env.POWERTOOLS_DEV = 'true'; @@ -1970,8 +2172,6 @@ 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 662976b339..fb6b7ed232 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -6,7 +6,6 @@ import { EnvironmentVariablesService } from '../../../src/config'; describe('Class: EnvironmentVariablesService', () => { - const ENVIRONMENT_VARIABLES = process.env; beforeEach(() => { @@ -19,9 +18,7 @@ describe('Class: EnvironmentVariablesService', () => { }); describe('Method: getAwsRegion', () => { - test('it returns the value of the environment variable AWS_REGION', () => { - // Prepare process.env.AWS_REGION = 'us-east-1'; const service = new EnvironmentVariablesService(); @@ -31,15 +28,11 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('us-east-1'); - }); - }); describe('Method: getCurrentEnvironment', () => { - test('it returns the value of the environment variable AWS_REGION', () => { - // Prepare process.env.ENVIRONMENT = 'stage'; const service = new EnvironmentVariablesService(); @@ -50,13 +43,10 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('stage'); }); - }); describe('Method: getFunctionMemory', () => { - test('it returns the value of the environment variable AWS_LAMBDA_FUNCTION_MEMORY_SIZE', () => { - // Prepare process.env.AWS_LAMBDA_FUNCTION_MEMORY_SIZE = '123456'; const service = new EnvironmentVariablesService(); @@ -66,15 +56,11 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toBe(123456); - }); - }); describe('Method: getFunctionName', () => { - test('it returns the value of the environment variable AWS_LAMBDA_FUNCTION_NAME', () => { - // Prepare process.env.AWS_LAMBDA_FUNCTION_NAME = 'my-lambda-function'; const service = new EnvironmentVariablesService(); @@ -84,15 +70,11 @@ 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', () => { - // Prepare process.env.AWS_LAMBDA_FUNCTION_VERSION = '1.4.0'; const service = new EnvironmentVariablesService(); @@ -102,15 +84,11 @@ 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"', () => { - // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true'; const service = new EnvironmentVariablesService(); @@ -120,11 +98,9 @@ describe('Class: EnvironmentVariablesService', () => { // 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(); @@ -134,11 +110,9 @@ describe('Class: EnvironmentVariablesService', () => { // 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(); @@ -148,15 +122,11 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); - }); - }); describe('Method: getLogLevel', () => { - test('it returns the value of the environment variable LOG_LEVEL', () => { - // Prepare process.env.LOG_LEVEL = 'ERROR'; const service = new EnvironmentVariablesService(); @@ -166,15 +136,11 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('ERROR'); - }); - }); describe('Method: getSampleRateValue', () => { - test('it returns the value of the environment variable POWERTOOLS_LOGGER_SAMPLE_RATE', () => { - // Prepare process.env.POWERTOOLS_LOGGER_SAMPLE_RATE = '0.01'; const service = new EnvironmentVariablesService(); @@ -184,15 +150,11 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(0.01); - }); - }); describe('Method: isDevMode', () => { - test('it returns true if the environment variable POWERTOOLS_DEV is "true"', () => { - // Prepare process.env.POWERTOOLS_DEV = 'true'; const service = new EnvironmentVariablesService(); @@ -202,11 +164,9 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(true); - }); test('it returns false if the environment variable POWERTOOLS_DEV is "false"', () => { - // Prepare process.env.POWERTOOLS_DEV = 'false'; const service = new EnvironmentVariablesService(); @@ -216,11 +176,9 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); - }); test('it returns false if the environment variable POWERTOOLS_DEV is NOT set', () => { - // Prepare process.env.POWERTOOLS_DEV = 'somethingsilly'; const service = new EnvironmentVariablesService(); @@ -230,11 +188,9 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); - }); test('it returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => { - // Prepare process.env.POWERTOOLS_DEV = 'somethingsilly'; const service = new EnvironmentVariablesService(); @@ -244,9 +200,6 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual(false); - }); - }); - -}); \ No newline at end of file +}); diff --git a/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts b/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts index 1aff6d111a..49daebe597 100644 --- a/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts +++ b/packages/logger/tests/unit/formatter/PowertoolLogFormatter.test.ts @@ -8,7 +8,6 @@ import { PowertoolLogFormatter } from '../../../src/formatter'; import { UnformattedAttributes } from '../../../src/types'; describe('Class: PowertoolLogFormatter', () => { - const mockDate = new Date(1466424490000); const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); @@ -17,9 +16,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', () => { - // Prepare const formatter = new PowertoolLogFormatter(); const unformattedAttributes: UnformattedAttributes = { @@ -50,11 +47,9 @@ 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', () => { - // Prepare const formatter = new PowertoolLogFormatter(); const unformattedAttributes: UnformattedAttributes = { @@ -72,7 +67,8 @@ describe('Class: PowertoolLogFormatter', () => { memoryLimitInMB: 123, functionVersion: '1.23.3', coldStart: true, - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:Example', + invokedFunctionArn: + 'arn:aws:lambda:eu-west-1:123456789012:function:Example', awsRequestId: 'abcdefg123456789', }, }; @@ -94,15 +90,11 @@ 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', () => { - // Prepare const formatter = new PowertoolLogFormatter(); const shouldThrow = (): void => { @@ -117,19 +109,21 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(Error); const formattedError = formatter.formatError(error); expect(formattedError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+$/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+$/ + ), message: 'Ouch!', name: 'Error', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(Error)); - }); 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 => { @@ -147,19 +141,21 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(Error); const formattedReferenceError = formatter.formatError(error); expect(formattedReferenceError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+$/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+$/ + ), message: 'doesNotExist is not defined', name: 'ReferenceError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(ReferenceError)); - }); 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 => { @@ -172,21 +168,27 @@ describe('Class: PowertoolLogFormatter', () => { } catch (error) { // Assess expect(error).toBeInstanceOf(AssertionError); - const formattedAssertionError = formatter.formatError(error); + const formattedAssertionError = formatter.formatError( + error + ); expect(formattedAssertionError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+/), - message: expect.stringMatching(/Expected values to be strictly equal/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+/ + ), + message: expect.stringMatching( + /Expected values to be strictly equal/ + ), name: 'AssertionError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(AssertionError)); - }); 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 => { @@ -201,10 +203,14 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(RangeError); const formattedRangeError = formatter.formatError(error); expect(formattedRangeError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+/ + ), message: 'The argument must be between 10 and 20', name: 'RangeError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } @@ -212,7 +218,6 @@ describe('Class: PowertoolLogFormatter', () => { }); 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 => { @@ -227,19 +232,21 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(SyntaxError); const formattedSyntaxError = formatter.formatError(error); expect(formattedSyntaxError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+/ + ), message: 'Unexpected identifier', name: 'SyntaxError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(SyntaxError)); - }); 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 => { @@ -258,19 +265,21 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(Error); const formattedTypeError = formatter.formatError(error); expect(formattedTypeError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+/ + ), message: expect.stringMatching(/Cannot read propert/), name: 'TypeError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(TypeError)); - }); 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 => { @@ -285,23 +294,23 @@ describe('Class: PowertoolLogFormatter', () => { expect(error).toBeInstanceOf(URIError); const formattedURIError = formatter.formatError(error); expect(formattedURIError).toEqual({ - location: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+/), + location: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+/ + ), message: 'URI malformed', name: 'URIError', - stack: expect.stringMatching(/PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/), + stack: expect.stringMatching( + /PowertoolLogFormatter.test.ts:[0-9]+:[0-9]+/ + ), }); } expect(shouldThrow).toThrowError(expect.any(URIError)); - }); - }); describe('Method: formatTimestamp', () => { - test('it returns a datetime value ISO 8601 compliant', () => { - // Prepare const formatter = new PowertoolLogFormatter(); @@ -310,18 +319,15 @@ 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', () => { - // Prepare const formatter = new PowertoolLogFormatter(); - const stack = 'Error: Things keep happening!\n' + + const stack = + 'Error: Things keep happening!\n' + ' at /home/foo/bar/file-that-threw-the-error.ts:22:5\n' + ' at SomeOther.function (/home/foo/bar/some-file.ts:154:19)'; @@ -330,11 +336,9 @@ 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', () => { - // Prepare const formatter = new PowertoolLogFormatter(); const stack = undefined; @@ -344,11 +348,9 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(errorLocation).toEqual(''); - }); test('when the stack IS NOT present, it returns a datetime value ISO 8601 compliant', () => { - // Prepare const formatter = new PowertoolLogFormatter(); const stack = 'A weird stack trace...'; @@ -358,9 +360,6 @@ describe('Class: PowertoolLogFormatter', () => { // Assess expect(errorLocation).toEqual(''); - }); - }); - -}); \ 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 4c05b0b49a..4f2c6ee743 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -4,13 +4,15 @@ * @group unit/logger/all */ import { Console } from 'console'; -import { ConfigServiceInterface, EnvironmentVariablesService } from '../../src/config'; +import { + ConfigServiceInterface, + EnvironmentVariablesService, +} from '../../src/config'; import { LogFormatter, PowertoolLogFormatter } from '../../src/formatter'; import { ConstructorOptions, LogLevelThresholds } from '../../src/types'; import { createLogger, Logger } from './../../src'; describe('Helper: createLogger function', () => { - const ENVIRONMENT_VARIABLES = process.env; const logLevelThresholds: LogLevelThresholds = { DEBUG: 8, @@ -19,7 +21,7 @@ describe('Helper: createLogger function', () => { ERROR: 20, CRITICAL: 24, SILENT: 28, - }; + }; beforeEach(() => { jest.resetModules(); @@ -31,9 +33,7 @@ describe('Helper: createLogger function', () => { }); describe('LoggerOptions constructor parameters', () => { - test('when no constructor parameters are set, returns a Logger instance with the options set in the environment variables', () => { - // Prepare const loggerOptions = undefined; @@ -42,26 +42,26 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - defaultServiceName: 'service_undefined', - logLevel: 'DEBUG', - logFormatter: expect.any(PowertoolLogFormatter), - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + defaultServiceName: 'service_undefined', + logLevel: 'DEBUG', + logFormatter: expect.any(PowertoolLogFormatter), + }) + ); }); test('when no parameters are set, returns a Logger instance with the correct properties', () => { - // Prepare const loggerOptions: ConstructorOptions = { logLevel: 'WARN', @@ -91,7 +91,7 @@ describe('Helper: createLogger function', () => { logLevel: 'WARN', console: expect.any(Console), logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: true, persistentLogAttributes: { @@ -104,11 +104,9 @@ describe('Helper: createLogger function', () => { serviceName: 'my-lambda-service', }, }); - }); test('when no constructor parameters and no environment variables are set, returns a Logger instance with the default properties', () => { - // Prepare const loggerOptions = undefined; delete process.env.POWERTOOLS_SERVICE_NAME; @@ -130,7 +128,7 @@ describe('Helper: createLogger function', () => { logLevel: 'INFO', console: expect.any(Console), logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -141,13 +139,11 @@ describe('Helper: createLogger function', () => { serviceName: 'service_undefined', }, }); - }); test('when a custom logFormatter is passed, returns a Logger instance with the correct properties', () => { - // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { logFormatter: expect.any(LogFormatter), }; @@ -156,26 +152,27 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: expect.any(LogFormatter), - })); + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'DEBUG', + logFormatter: expect.any(LogFormatter), + }) + ); }); test('when a custom serviceName is passed, returns a Logger instance with the correct properties', () => { - // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { serviceName: 'my-backend-service', }; @@ -184,25 +181,25 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'my-backend-service', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: {}, - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'my-backend-service', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'DEBUG', + logFormatter: {}, + }) + ); }); test('when a custom uppercase logLevel is passed, returns a Logger instance with the correct properties', () => { - // Prepare const loggerOptions: ConstructorOptions = { logLevel: 'ERROR', @@ -213,25 +210,25 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'ERROR', - logFormatter: expect.any(PowertoolLogFormatter), - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'ERROR', + logFormatter: expect.any(PowertoolLogFormatter), + }) + ); }); - - test('when a custom lowercase logLevel is passed, returns a Logger instance with the correct properties', () => { + test('when a custom lowercase logLevel is passed, returns a Logger instance with the correct properties', () => { // Prepare const loggerOptions: ConstructorOptions = { logLevel: 'warn', @@ -242,25 +239,25 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'WARN', - logFormatter: expect.any(PowertoolLogFormatter), - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'WARN', + logFormatter: expect.any(PowertoolLogFormatter), + }) + ); }); test('when no log level is set, returns a Logger instance with INFO level', () => { - // Prepare const loggerOptions: ConstructorOptions = {}; delete process.env.LOG_LEVEL; @@ -281,7 +278,7 @@ describe('Helper: createLogger function', () => { logLevel: 'INFO', console: expect.any(Console), logLevelThresholds: { - ...logLevelThresholds + ...logLevelThresholds, }, logsSampled: false, persistentLogAttributes: {}, @@ -292,13 +289,11 @@ describe('Helper: createLogger function', () => { serviceName: 'hello-world', }, }); - }); test('when a custom sampleRateValue is passed, returns a Logger instance with the correct properties', () => { - // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { sampleRateValue: 1, }; @@ -307,25 +302,25 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: true, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: 1, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: {}, - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: true, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: 1, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'DEBUG', + logFormatter: {}, + }) + ); }); test('when a custom customConfigService is passed, returns a Logger instance with the correct properties', () => { - const configService: ConfigServiceInterface = { get(name: string): string { return `a-string-from-${name}`; @@ -351,10 +346,9 @@ describe('Helper: createLogger function', () => { isValueTrue(): boolean { return true; }, - }; // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { customConfigService: configService, }; @@ -363,27 +357,27 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: 'dev', - serviceName: 'my-backend-service', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: configService, - logLevel: 'INFO', - logFormatter: {}, - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: 'dev', + serviceName: 'my-backend-service', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: configService, + logLevel: 'INFO', + logFormatter: {}, + }) + ); }); test('when custom persistentLogAttributes is passed, returns a Logger instance with the correct properties', () => { - // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { persistentLogAttributes: { aws_account_id: '123456789012', aws_region: 'eu-west-1', @@ -399,34 +393,34 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: { - aws_account_id: '123456789012', - aws_region: 'eu-west-1', - logger: { - name: 'aws-lambda-powertool-typescript', - version: '0.2.4', + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: { + aws_account_id: '123456789012', + aws_region: 'eu-west-1', + logger: { + name: 'aws-lambda-powertool-typescript', + version: '0.2.4', + }, }, - }, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: {}, - })); - + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'DEBUG', + logFormatter: {}, + }) + ); }); test('when a custom environment is passed, returns a Logger instance with the correct properties', () => { - // Prepare - const loggerOptions:ConstructorOptions = { + const loggerOptions: ConstructorOptions = { environment: 'dev', }; @@ -435,23 +429,22 @@ describe('Helper: createLogger function', () => { // Assess expect(logger).toBeInstanceOf(Logger); - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: 'dev', - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: {}, - })); - + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: 'dev', + serviceName: 'hello-world', + }, + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + 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 c12680a1c5..2a40a211c6 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -3,9 +3,14 @@ * * @group unit/logger/all */ - -import { ContextExamples as dummyContext, Events as dummyEvent } from '@aws-lambda-powertools/commons'; -import { ConfigServiceInterface, EnvironmentVariablesService } from '../../../src/config'; +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'; import middy from '@middy/core'; @@ -17,7 +22,6 @@ const mockDate = new Date(1466424490000); 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; @@ -25,7 +29,9 @@ describe('Middy middleware', () => { beforeEach(() => { jest.resetModules(); dateSpy.mockClear(); - jest.spyOn(process.stdout, 'write').mockImplementation(() => null as unknown as boolean); + jest + .spyOn(process.stdout, 'write') + .mockImplementation(() => null as unknown as boolean); process.env = { ...ENVIRONMENT_VARIABLES }; }); @@ -34,11 +40,8 @@ describe('Middy middleware', () => { }); describe('injectLambdaContext', () => { - describe('Feature: add context data', () => { - test('when a logger object is passed, it adds the context to the logger instance', async () => { - // Prepare const logger = new Logger(); const handler = middy((): void => { @@ -49,40 +52,41 @@ describe('Middy middleware', () => { await handler(event, context); // Assess - expect(logger).toEqual(expect.objectContaining({ - logsSampled: false, - persistentLogAttributes: {}, - powertoolLogData: { - sampleRateValue: undefined, - awsRegion: 'eu-west-1', - environment: '', - lambdaContext: { - awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - coldStart: true, - functionName: 'foo-bar-function', - functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - memoryLimitInMB: 128, + expect(logger).toEqual( + expect.objectContaining({ + logsSampled: false, + persistentLogAttributes: {}, + powertoolLogData: { + sampleRateValue: undefined, + awsRegion: 'eu-west-1', + environment: '', + lambdaContext: { + awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + coldStart: true, + functionName: 'foo-bar-function', + functionVersion: '$LATEST', + invokedFunctionArn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + memoryLimitInMB: 128, + }, + serviceName: 'hello-world', }, - serviceName: 'hello-world', - }, - envVarsService: expect.any(EnvironmentVariablesService), - customConfigService: undefined, - logLevel: 'DEBUG', - logFormatter: expect.any(PowertoolLogFormatter), - })); - + envVarsService: expect.any(EnvironmentVariablesService), + customConfigService: undefined, + logLevel: 'DEBUG', + logFormatter: expect.any(PowertoolLogFormatter), + }) + ); }); 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 handler = middy((): void => { logger.info('This is an INFO log with some context'); anotherLogger.info('This is an INFO log with some context'); - }).use(injectLambdaContext([ logger, anotherLogger ])); + }).use(injectLambdaContext([logger, anotherLogger])); // Act await handler(event, context); @@ -100,7 +104,8 @@ describe('Middy middleware', () => { coldStart: true, functionName: 'foo-bar-function', functionVersion: '$LATEST', - invokedFunctionArn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + invokedFunctionArn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', memoryLimitInMB: 128, }, serviceName: 'hello-world', @@ -113,123 +118,127 @@ describe('Middy middleware', () => { }); expect(logger).toEqual(expectation); expect(anotherLogger).toEqual(expectation); - }); - }); - }); describe('Feature: clear state', () => { - test('when enabled, the persistent log attributes added within the handler scope are removed after the invocation ends', async () => { - // Prepare const logger = new Logger({ logLevel: 'DEBUG', persistentLogAttributes: { foo: 'bar', - biz: 'baz' - } + biz: 'baz', + }, }); const handler = middy((): void => { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: '1234' } + 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'); }).use(injectLambdaContext(logger, { clearState: true })); - const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; - + const persistentAttribsBeforeInvocation = { + ...logger.getPersistentLogAttributes(), + }; + // Act await handler(event, context); - + // Assess - const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; + const persistentAttribsAfterInvocation = { + ...logger.getPersistentLogAttributes(), + }; expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', - biz: 'baz' + biz: 'baz', }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); - + expect(persistentAttribsAfterInvocation).toEqual( + persistentAttribsBeforeInvocation + ); }); 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({ logLevel: 'DEBUG', persistentLogAttributes: { foo: 'bar', - biz: 'baz' - } + biz: 'baz', + }, }); const handler = middy((): void => { // Only add these persistent for the scope of this lambda handler logger.appendKeys({ - details: { user_id: '1234' } + 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!'); }).use(injectLambdaContext(logger, { clearState: true })); - const persistentAttribsBeforeInvocation = { ...logger.getPersistentLogAttributes() }; - + const persistentAttribsBeforeInvocation = { + ...logger.getPersistentLogAttributes(), + }; + // Act & Assess - await expect(handler(event, context)) - .rejects.toThrow(); - const persistentAttribsAfterInvocation = { ...logger.getPersistentLogAttributes() }; + await expect(handler(event, context)).rejects.toThrow(); + const persistentAttribsAfterInvocation = { + ...logger.getPersistentLogAttributes(), + }; expect(persistentAttribsBeforeInvocation).toEqual({ foo: 'bar', - biz: 'baz' + biz: 'baz', }); - expect(persistentAttribsAfterInvocation).toEqual(persistentAttribsBeforeInvocation); - + expect(persistentAttribsAfterInvocation).toEqual( + persistentAttribsBeforeInvocation + ); }); - }); describe('Feature: log event', () => { - test('when enabled, it logs the event', async () => { - // Prepare const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); const handler = middy((): void => { logger.info('This is an INFO log with some context'); - }).use(injectLambdaContext(logger , { logEvent: true })); + }).use(injectLambdaContext(logger, { logEvent: true })); // Act await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: '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: { - key1: 'value1', - key2: 'value2', - key3: 'value3', - } - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'Lambda invocation event', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + event: { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }, + }) + ); }); test('when enabled, while also having a custom configService, it logs the event', async () => { - // Prepare const configService: ConfigServiceInterface = { get(name: string): string { @@ -261,111 +270,128 @@ describe('Middy middleware', () => { const logger = new Logger({ customConfigService: configService, }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); const handler = middy((): void => { logger.info('This is an INFO log with some context'); - }).use(injectLambdaContext(logger , { logEvent: true })); - + }).use(injectLambdaContext(logger, { logEvent: true })); + // Act await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: '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: { - key1: 'value1', - key2: 'value2', - key3: 'value3', - } - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'Lambda invocation event', + service: 'my-backend-service', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + event: { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }, + }) + ); }); 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 consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); const handler = middy((): void => { logger.info('This is an INFO log with some context'); }).use(injectLambdaContext(logger)); - + // Act await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(2); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: '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: { - key1: 'value1', - key2: 'value2', - key3: 'value3', - } - })); - + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'Lambda invocation event', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + event: { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }, + }) + ); }); - test('when disabled in the middleware, but enabled via POWERTOOLS_LOGGER_LOG_EVENT env var, it still doesn\'t log the event', async () => { - + test('when disabled in the middleware, but enabled via POWERTOOLS_LOGGER_LOG_EVENT env var, it still does not log the event', async () => { // Prepare process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'true'; const logger = new Logger(); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); const handler = middy((): void => { logger.info('This is an INFO log'); }).use(injectLambdaContext(logger, { logEvent: false })); - + // Act await handler(event, context); // Assess expect(consoleSpy).toBeCalledTimes(1); - expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ - cold_start: true, - function_arn: 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', - function_memory_size: 128, - function_name: 'foo-bar-function', - function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', - level: 'INFO', - message: 'This is an INFO log', - service: 'hello-world', - timestamp: '2016-06-20T12:08:10.000Z', - xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', - })); + expect(consoleSpy).toHaveBeenNthCalledWith( + 1, + JSON.stringify({ + cold_start: true, + function_arn: + 'arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function', + function_memory_size: 128, + function_name: 'foo-bar-function', + function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678', + level: 'INFO', + message: 'This is an INFO log', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }) + ); }); test('when logEvent and clearState are both TRUE, and the logger has persistent attributes, any key added in the handler is cleared properly', async () => { - const logger = new Logger({ persistentLogAttributes: { version: '1.0.0', - } + }, }); - const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); - const handler = middy(async (event: { foo: string }, _context: Context) => { - logger.appendKeys({ foo: event.foo }); - }).use(injectLambdaContext(logger, { logEvent: true, clearState: true })); + const consoleSpy = jest + .spyOn(logger['console'], 'info') + .mockImplementation(); + const handler = middy( + async (event: { foo: string }, _context: Context) => { + logger.appendKeys({ foo: event.foo }); + } + ).use(injectLambdaContext(logger, { logEvent: true, clearState: true })); await handler({ foo: 'bar' }, {} as Context); await handler({ foo: 'baz' }, {} as Context); @@ -377,33 +403,29 @@ describe('Middy middleware', () => { for (let i = 1; i === 5; i++) { expect(consoleSpy).toHaveBeenNthCalledWith( i, - expect.stringContaining('\"message\":\"Lambda invocation event\"'), + expect.stringContaining('"message":"Lambda invocation event"') ); expect(consoleSpy).toHaveBeenNthCalledWith( i, - expect.stringContaining('\"version\":\"1.0.0\"'), + expect.stringContaining('"version":"1.0.0"') ); } expect(consoleSpy).toHaveBeenNthCalledWith( 2, - expect.not.stringContaining('\"foo\":\"bar\"') + expect.not.stringContaining('"foo":"bar"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 3, - expect.not.stringContaining('\"foo\":\"baz\"') + expect.not.stringContaining('"foo":"baz"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 4, - expect.not.stringContaining('\"foo\":\"biz\"') + expect.not.stringContaining('"foo":"biz"') ); expect(consoleSpy).toHaveBeenNthCalledWith( 5, - expect.not.stringContaining('\"foo\":\"buz\"') + expect.not.stringContaining('"foo":"buz"') ); - }); - }); - }); -